Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

esp_hid_device bluetooth example doesn't work properly with input passkey (IDFGH-10566) #11806

Closed
3 tasks done
jeremyherbert opened this issue Jul 5, 2023 · 8 comments
Closed
3 tasks done
Assignees
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally Type: Bug bugs in IDF

Comments

@jeremyherbert
Copy link
Contributor

jeremyherbert commented Jul 5, 2023

Answers checklist.

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

IDF version.

v5.1

Operating System used.

macOS

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-C3-WROOM-02

Power Supply used.

External 3.3V

What is the expected behavior?

After modifying the example to accept a passkey (entered over SPI) I expect the HID device to work immediately after pairing.

What is the actual behavior?

The HID device does not work, even though pairing was successful.

Steps to reproduce.

  1. Download, build and flash the attached code to an ESP32-C3, which is a modified version of the sample that does the following:
  • sets the IO capability to input only
  • enables the passkey to be sent to the device using the spi slave driver. You transmit "p123456" over spi and then it calls esp_ble_passkey_reply(passkey_auth_target, true, passkey);
  1. Try to connect to the device (I am using mac os 12.4) and you should get a pairing code, send it over SPI
  2. Authentication succeeds with ESP_GAP_BLE_AUTH_CMPL_EVT being triggered and printed to UART log. Device is listed as connected on the PC, but the event ESP_HIDD_CONNECT_EVENT is never sent to the the hidd callback and HID messages are not sent to the PC
  3. Power cycle the esp32-c3
  4. PC doesn't automatically connect to the device. Double clicking on the device in the bluetooth preferences does connect to the device, and it doesn't ask to pair again. ESP_HIDD_CONNECT_EVENT is now triggered and HID messages are finally able to be sent
  5. After power cycling again, device connects to the PC automatically and is able to send HID messages.

esp32-c3-pairing.zip

Debug Logs.

first connection (pairing, but fails to start HID):

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x4 (DOWNLOAD(USB/UART0/1))
Saved PC:0x40388544
waiting for download
ÀOHAIÀÀÀn3f"Þ1&'þ1ffþp#æ&þn3&f63fN"fþ7&fþ23nf¾qfþ"Î3fÎR3ffð7&æþFNþnÿîfþ#ÎæR3ÿæò7öfþF3ffffþ~nææÀ"Ç&óæþÆý"Æö6w_âþþ"3Nþޙfþ&3fðfþæ63fÀ3fNgfþ&2ã&ÀÆ2&þN2ãfþАsf"ðgfÎÎs&þþâ3fþfg&2ng&þò3fNgfNâ3fþÐþ"&þFn3f&ã&þ"3NÎÎ3NþÀ3f>þ23þþΞþfæ>þÀófþP~>æÆý2ƾþ>>gþþàæfþö6f&þ°çvþò>fþè'ÿþþþN3&~þn3fE
SP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40380836
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd5820,len:0x1704
load:0x403cc710,len:0x968
load:0x403ce710,len:0x2f68
entry 0x403cc710
I (24) boot: ESP-IDF v5.1 2nd stage bootloader
I (24) boot: compile time Jul  5 2023 17:52:58
I (25) boot: chip revision: v0.3
I (27) boot.esp32c3: SPI Speed      : 80MHz
I (32) boot.esp32c3: SPI Mode       : DIO
I (37) boot.esp32c3: SPI Flash Size : 2MB
I (41) boot: Enabling RNG early entropy source...
I (47) boot: Partition Table:
I (50) boot: ## Label            Usage          Type ST Offset   Length
I (58) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (65) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (73) boot:  2 factory          factory app      00 00 00010000 00100000
I (80) boot: End of partition table
I (84) esp_image: segment 0: paddr=00010020 vaddr=3c0a0020 size=24458h (148568) map
I (116) esp_image: segment 1: paddr=00034480 vaddr=3fc91000 size=0215ch (  8540) load
I (125) esp_image: segment 2: paddr=000365e4 vaddr=40380000 size=09a34h ( 39476) load
I (133) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=9773ch (620348) map
I (232) esp_image: segment 4: paddr=000d7764 vaddr=40389a34 size=07438h ( 29752) load
I (243) boot: Loaded app from partition at offset 0x10000
I (243) boot: Disabling RNG early entropy source...
I (254) cpu_start: Unicore app
I (255) cpu_start: Pro cpu up.
I (263) cpu_start: Pro cpu start user code
I (263) cpu_start: cpu freq: 160000000 Hz
I (263) cpu_start: Application information:
I (266) cpu_start: Project name:     esp_hid_secure_pairing
I (273) cpu_start: App version:      1
I (277) cpu_start: Compile time:     Jul  5 2023 17:51:44
I (283) cpu_start: ELF file SHA256:  e611892f786f8407...
I (289) cpu_start: ESP-IDF:          v5.1
I (294) cpu_start: Min chip rev:     v0.3
I (299) cpu_start: Max chip rev:     v0.99
I (303) cpu_start: Chip rev:         v0.3
I (308) heap_init: Initializing. RAM available for dynamic allocation:
I (315) heap_init: At 3FC97900 len 00044E10 (275 KiB): DRAM
I (322) heap_init: At 3FCDC710 len 00002950 (10 KiB): STACK/DRAM
I (328) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM
I (335) spi_flash: detected chip: generic
I (339) spi_flash: flash io: dio
W (343) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (356) sleep: Configure to isolate all GPIO pins in sleep state
I (363) sleep: Enable automatic switching of GPIO sleep configuration
I (370) coexist: coex firmware version: ebddf30
I (375) coexist: coexist rom version 9387209
I (381) app_start: Starting scheduler on CPU0
I (385) main_task: Started on CPU0
I (385) main_task: Calling app_main()
I (395) HID_DEV_DEMO: setting hid gap, mode:1
I (395) ESP_HID_GAP: Starting SPI transaction
I (395) BLE_INIT: BT controller compile version [85b425c]
I (405) phy_init: phy_version 970,1856f88,May 10 2023,17:44:12
I (455) BLE_INIT: Bluetooth MAC: 60:55:f9:83:ed:c2
W (475) BT_BTM: BTM_BleWriteAdvData, Partial data write into ADV
I (475) HID_DEV_DEMO: setting ble device
I (495) HID_DEV_BLE: START
I (495) main_task: Returned from app_main()
I (11855) HID_DEV_BLE: CONNECT
I (11855) HID_DEV_DEMO: Send volume key
I (12565) ESP_HID_GAP: BLE GAP PASSKEY_REQ
I (13955) HID_DEV_DEMO: Send volume key
I (16055) HID_DEV_DEMO: Send volume key
I (18155) HID_DEV_DEMO: Send volume key
I (20255) HID_DEV_DEMO: Send volume key
I (21275) ESP_HID_GAP: Received: p254298 (size: 56)
I (21275) ESP_HID_GAP: Sending passkey 254298
I (21275) ESP_HID_GAP: Starting SPI transaction
W (22195) BT_SMP: FOR LE SC LTK IS USED INSTEAD OF STK
I (22265) ESP_HID_GAP: BLE GAP KEY type = ESP_LE_KEY_LENC
I (22265) ESP_HID_GAP: BLE GAP KEY type = ESP_LE_KEY_PENC
I (22265) ESP_HID_GAP: BLE GAP KEY type = ESP_LE_KEY_LID
I (22335) ESP_HID_GAP: BLE GAP KEY type = ESP_LE_KEY_PID
I (22345) ESP_HID_GAP: BLE GAP AUTH SUCCESS
I (22355) HID_DEV_DEMO: Send volume key
I (24455) HID_DEV_DEMO: Send volume key
I (26555) HID_DEV_DEMO: Send volume key
I (28655) HID_DEV_DEMO: Send volume key
I (30755) HID_DEV_DEMO: Send volume key
I (32855) HID_DEV_DEMO: Send volume key
I (34955) HID_DEV_DEMO: Send volume key
I (37055) HID_DEV_DEMO: Send volume key
I (39155) HID_DEV_DEMO: Send volume key
I (41255) HID_DEV_DEMO: Send volume key
I (43355) HID_DEV_DEMO: Send volume key



second connection (manual forced connection inside bluetooth preferences, does not connect automatically):

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd5820,len:0x1704
load:0x403cc710,len:0x968
load:0x403ce710,len:0x2f68
entry 0x403cc710
I (30) boot: ESP-IDF v5.1 2nd stage bootloader
I (30) boot: compile time Jul  5 2023 17:52:58
I (30) boot: chip revision: v0.3
I (33) boot.esp32c3: SPI Speed      : 80MHz
I (38) boot.esp32c3: SPI Mode       : DIO
I (43) boot.esp32c3: SPI Flash Size : 2MB
I (47) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (71) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (86) boot: End of partition table
I (90) esp_image: segment 0: paddr=00010020 vaddr=3c0a0020 size=24458h (148568) map
I (122) esp_image: segment 1: paddr=00034480 vaddr=3fc91000 size=0215ch (  8540) load
I (124) esp_image: segment 2: paddr=000365e4 vaddr=40380000 size=09a34h ( 39476) load
I (136) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=9773ch (620348) map
I (235) esp_image: segment 4: paddr=000d7764 vaddr=40389a34 size=07438h ( 29752) load
I (246) boot: Loaded app from partition at offset 0x10000
I (247) boot: Disabling RNG early entropy source...
I (258) cpu_start: Unicore app
I (258) cpu_start: Pro cpu up.
I (267) cpu_start: Pro cpu start user code
I (267) cpu_start: cpu freq: 160000000 Hz
I (267) cpu_start: Application information:
I (270) cpu_start: Project name:     esp_hid_secure_pairing
I (276) cpu_start: App version:      1
I (281) cpu_start: Compile time:     Jul  5 2023 17:51:44
I (287) cpu_start: ELF file SHA256:  e611892f786f8407...
I (293) cpu_start: ESP-IDF:          v5.1
I (297) cpu_start: Min chip rev:     v0.3
I (302) cpu_start: Max chip rev:     v0.99
I (307) cpu_start: Chip rev:         v0.3
I (312) heap_init: Initializing. RAM available for dynamic allocation:
I (319) heap_init: At 3FC97900 len 00044E10 (275 KiB): DRAM
I (325) heap_init: At 3FCDC710 len 00002950 (10 KiB): STACK/DRAM
I (332) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM
I (339) spi_flash: detected chip: generic
I (343) spi_flash: flash io: dio
W (347) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (360) sleep: Configure to isolate all GPIO pins in sleep state
I (367) sleep: Enable automatic switching of GPIO sleep configuration
I (374) coexist: coex firmware version: ebddf30
I (379) coexist: coexist rom version 9387209
I (384) app_start: Starting scheduler on CPU0
I (389) main_task: Started on CPU0
I (389) main_task: Calling app_main()
I (399) HID_DEV_DEMO: setting hid gap, mode:1
I (399) ESP_HID_GAP: Starting SPI transaction
I (399) BLE_INIT: BT controller compile version [85b425c]
I (409) phy_init: phy_version 970,1856f88,May 10 2023,17:44:12
I (449) BLE_INIT: Bluetooth MAC: 60:55:f9:83:ed:c2
W (479) BT_BTM: BTM_BleWriteAdvData, Partial data write into ADV
I (479) HID_DEV_DEMO: setting ble device
I (489) HID_DEV_BLE: START
I (489) main_task: Returned from app_main()
I (11849) ESP_HID_GAP: BLE GAP AUTH SUCCESS
I (11849) HID_DEV_BLE: CONNECT
I (11849) HID_DEV_DEMO: Send volume key
W (12049) BT_L2CAP: le con upd: err_stat=0x1e
I (13949) HID_DEV_DEMO: Send volume key
I (16049) HID_DEV_DEMO: Send volume key
I (18149) HID_DEV_DEMO: Send volume key
I (20249) HID_DEV_DEMO: Send volume key
I (22349) HID_DEV_DEMO: Send volume key


third connection (automatically connects):

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd5820,len:0x1704
load:0x403cc710,len:0x968
load:0x403ce710,len:0x2f68
entry 0x403cc710
I (30) boot: ESP-IDF v5.1 2nd stage bootloader
I (30) boot: compile time Jul  5 2023 17:52:58
I (30) boot: chip revision: v0.3
I (33) boot.esp32c3: SPI Speed      : 80MHz
I (38) boot.esp32c3: SPI Mode       : DIO
I (43) boot.esp32c3: SPI Flash Size : 2MB
I (47) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (64) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (71) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (86) boot: End of partition table
I (90) esp_image: segment 0: paddr=00010020 vaddr=3c0a0020 size=24458h (148568) map
I (122) esp_image: segment 1: paddr=00034480 vaddr=3fc91000 size=0215ch (  8540) load
I (124) esp_image: segment 2: paddr=000365e4 vaddr=40380000 size=09a34h ( 39476) load
I (136) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=9773ch (620348) map
I (235) esp_image: segment 4: paddr=000d7764 vaddr=40389a34 size=07438h ( 29752) load
I (246) boot: Loaded app from partition at offset 0x10000
I (247) boot: Disabling RNG early entropy source...
I (258) cpu_start: Unicore app
I (258) cpu_start: Pro cpu up.
I (267) cpu_start: Pro cpu start user code
I (267) cpu_start: cpu freq: 160000000 Hz
I (267) cpu_start: Application information:
I (270) cpu_start: Project name:     esp_hid_secure_pairing
I (276) cpu_start: App version:      1
I (281) cpu_start: Compile time:     Jul  5 2023 17:51:44
I (287) cpu_start: ELF file SHA256:  e611892f786f8407...
I (293) cpu_start: ESP-IDF:          v5.1
I (297) cpu_start: Min chip rev:     v0.3
I (302) cpu_start: Max chip rev:     v0.99
I (307) cpu_start: Chip rev:         v0.3
I (312) heap_init: Initializing. RAM available for dynamic allocation:
I (319) heap_init: At 3FC97900 len 00044E10 (275 KiB): DRAM
I (325) heap_init: At 3FCDC710 len 00002950 (10 KiB): STACK/DRAM
I (332) heap_init: At 50000020 len 00001FE0 (7 KiB): RTCRAM
I (339) spi_flash: detected chip: generic
I (343) spi_flash: flash io: dio
W (347) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (360) sleep: Configure to isolate all GPIO pins in sleep state
I (367) sleep: Enable automatic switching of GPIO sleep configuration
I (374) coexist: coex firmware version: ebddf30
I (379) coexist: coexist rom version 9387209
I (384) app_start: Starting scheduler on CPU0
I (389) main_task: Started on CPU0
I (389) main_task: Calling app_main()
I (399) HID_DEV_DEMO: setting hid gap, mode:1
I (399) ESP_HID_GAP: Starting SPI transaction
I (399) BLE_INIT: BT controller compile version [85b425c]
I (409) phy_init: phy_version 970,1856f88,May 10 2023,17:44:12
I (459) BLE_INIT: Bluetooth MAC: 60:55:f9:83:ed:c2
W (479) BT_BTM: BTM_BleWriteAdvData, Partial data write into ADV
I (479) HID_DEV_DEMO: setting ble device
I (489) HID_DEV_BLE: START
I (489) main_task: Returned from app_main()
I (649) ESP_HID_GAP: BLE GAP AUTH SUCCESS
I (649) HID_DEV_BLE: CONNECT
I (649) HID_DEV_DEMO: Send volume key
W (819) BT_L2CAP: le con upd: err_stat=0x1e
I (2749) HID_DEV_DEMO: Send volume key
I (4849) HID_DEV_DEMO: Send volume key
I (6949) HID_DEV_DEMO: Send volume key
I (9049) HID_DEV_DEMO: Send volume key

More Information.

I tried to connect to the device on Ubuntu 22.04 over BLE, but it doesn't even show a pairing code and just works as-is. I am also not sure why this is the case, but I think that is an ubuntu problem.

Also, for some reason the esp_hid library seems to disable MITM protection?

esp_ble_set_encryption(param->connect.remote_bda, ESP_BLE_SEC_ENCRYPT_NO_MITM);

@jeremyherbert jeremyherbert added the Type: Bug bugs in IDF label Jul 5, 2023
@espressif-bot espressif-bot added the Status: Opened Issue is new label Jul 5, 2023
@github-actions github-actions bot changed the title esp_hid_device bluetooth example doesn't work properly with input passkey esp_hid_device bluetooth example doesn't work properly with input passkey (IDFGH-10566) Jul 5, 2023
@jeremyherbert
Copy link
Contributor Author

This seems to be something to do with the way the controller is interrogating the GATT server. When I first connect to the device, System Report shows:

  ESP BLE HID2:
  Address:	60:55:F9:83:ED:C2
  Vendor ID:	0x16C0
  Product ID:	0x05DF
  Services:	0x400000 < BLE >

But after power cycling and manually reconnecting (note that the battery level is now visible):

  ESP BLE HID2:
  Address:	60:55:F9:83:ED:C2
  Vendor ID:	0x16C0
  Product ID:	0x05DF
  Battery Level:	100%
  Services:	0x400000 < BLE >

So it seems that the GATT interrogation is failing somewhere

@esp-zhp
Copy link
Collaborator

esp-zhp commented Jul 5, 2023

Got it, I will check it later.

@jeremyherbert
Copy link
Contributor Author

jeremyherbert commented Jul 5, 2023

I tried to collect some logs with more debugging enabled (only after the auth is complete):

This is the first connection:

I (123317) ESP_HID_GAP: BLE GAP AUTH SUCCESS
D (124337) BT_GATT: gatt_get_ch_state: ch_state=4
D (124337) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (124337) BT_GATT: read_attr_value uuid=0x2a00 perm=0x1 sec_flag=0x34 offset=0 read_long=0
D (124347) BT_GAP: gap_ble_s_attr_request_cback : recv type (0x01)
D (124357) BT_GAP: GATT_UUID_GAP_DEVICE_NAME len=0x000c
I (124357) BT_GATT: GATTS_SendRsp: conn_id: 2  trans_id: 11  Status: 0x0000
D (124367) BT_GATT: gatt_get_ch_state: ch_state=4
D (124377) BT_GATT: gatt_sr_process_app_rsp gatt_if=2
D (124377) BT_GATT: gatt_dequeue_sr_cmd
D (124377) BT_GATT: gatt_sr_process_app_rsp ret_code=0
D (124437) BT_GATT: gatt_get_ch_state: ch_state=4
D (124437) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (124437) BT_GATT: read_attr_value uuid=0x2803 perm=0x1 sec_flag=0x34 offset=0 read_long=0
D (124447) BT_GATT: gatt_dequeue_sr_cmd
D (124467) BT_GATT: gatt_get_ch_state: ch_state=4
D (124467) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (124487) BT_GATT: gatt_get_ch_state: ch_state=4
D (124507) BT_GATT: gatt_get_ch_state: ch_state=4
D (124507) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x002b offset=0 len=2 sec_flag=0x34 key_size=16
D (124507) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
I (124517) BT_GATT: GATT_GetConnectionInfor conn_id=3
D (124527) BT_GATT: gatt_dequeue_sr_cmd
V (124527) BLE_HIDD: Battery CCC: Notify: On, Indicate: Off
D (124537) BT_GATT: gatt_get_ch_state: ch_state=4
D (124537) BT_GATT: read_attr_value uuid=0x2a19 perm=0x1 sec_flag=0x34 offset=0 read_long=0
I (124547) HID_DEV_DEMO: Send Volume
D (124557) BT_GATT: gatt_get_ch_state: ch_state=4
I (124557) BT_GATT: GATT_GetConnectionInfor conn_id=3
D (124567) BT_GATT: gatt_dequeue_sr_cmd
I (124567) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (124577) BT_GATT: GATTS_HandleValueNotification
D (124577) BT_GATT: gatt_get_ch_state: ch_state=4
D (124587) BLE_HIDD: Battery READ 100
V (124587) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (124637) BT_GATT: gatt_get_ch_state: ch_state=4
I (124637) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (124637) BT_GATT: GATTS_HandleValueNotification
D (124637) BT_GATT: gatt_get_ch_state: ch_state=4
V (124647) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (126647) HID_DEV_DEMO: Send Volume
D (126647) BT_GATT: gatt_get_ch_state: ch_state=4
I (126647) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (126647) BT_GATT: GATTS_HandleValueNotification
D (126647) BT_GATT: gatt_get_ch_state: ch_state=4
V (126657) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (126707) BT_GATT: gatt_get_ch_state: ch_state=4
I (126707) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (126707) BT_GATT: GATTS_HandleValueNotification
D (126707) BT_GATT: gatt_get_ch_state: ch_state=4
V (126717) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (128717) HID_DEV_DEMO: Send Volume
D (128717) BT_GATT: gatt_get_ch_state: ch_state=4
I (128717) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (128717) BT_GATT: GATTS_HandleValueNotification
D (128717) BT_GATT: gatt_get_ch_state: ch_state=4
V (128727) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (128777) BT_GATT: gatt_get_ch_state: ch_state=4
I (128777) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (128777) BT_GATT: GATTS_HandleValueNotification
D (128777) BT_GATT: gatt_get_ch_state: ch_state=4
V (128787) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (130787) HID_DEV_DEMO: Send Volume
D (130787) BT_GATT: gatt_get_ch_state: ch_state=4
I (130787) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (130787) BT_GATT: GATTS_HandleValueNotification
D (130787) BT_GATT: gatt_get_ch_state: ch_state=4
V (130797) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (130847) BT_GATT: gatt_get_ch_state: ch_state=4
I (130847) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (130847) BT_GATT: GATTS_HandleValueNotification
D (130847) BT_GATT: gatt_get_ch_state: ch_state=4
V (130857) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (132857) HID_DEV_DEMO: Send Volume
D (132857) BT_GATT: gatt_get_ch_state: ch_state=4
I (132857) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (132857) BT_GATT: GATTS_HandleValueNotification
D (132857) BT_GATT: gatt_get_ch_state: ch_state=4
V (132867) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (132917) BT_GATT: gatt_get_ch_state: ch_state=4
I (132917) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (132917) BT_GATT: GATTS_HandleValueNotification
D (132917) BT_GATT: gatt_get_ch_state: ch_state=4
V (132927) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (134927) HID_DEV_DEMO: Send Volume
D (134927) BT_GATT: gatt_get_ch_state: ch_state=4
I (134927) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (134927) BT_GATT: GATTS_HandleValueNotification
D (134927) BT_GATT: gatt_get_ch_state: ch_state=4
V (134937) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (134987) BT_GATT: gatt_get_ch_state: ch_state=4
I (134987) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (134987) BT_GATT: GATTS_HandleValueNotification
D (134987) BT_GATT: gatt_get_ch_state: ch_state=4
V (134997) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (136997) HID_DEV_DEMO: Send Volume
D (136997) BT_GATT: gatt_get_ch_state: ch_state=4
I (136997) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (136997) BT_GATT: GATTS_HandleValueNotification
D (136997) BT_GATT: gatt_get_ch_state: ch_state=4
V (137007) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (137057) BT_GATT: gatt_get_ch_state: ch_state=4
I (137057) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (137057) BT_GATT: GATTS_HandleValueNotification
D (137057) BT_GATT: gatt_get_ch_state: ch_state=4
V (137067) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (139067) HID_DEV_DEMO: Send Volume
D (139067) BT_GATT: gatt_get_ch_state: ch_state=4
I (139067) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (139067) BT_GATT: GATTS_HandleValueNotification
D (139067) BT_GATT: gatt_get_ch_state: ch_state=4
V (139077) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (139127) BT_GATT: gatt_get_ch_state: ch_state=4
I (139127) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (139127) BT_GATT: GATTS_HandleValueNotification
D (139127) BT_GATT: gatt_get_ch_state: ch_state=4
V (139137) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (141137) HID_DEV_DEMO: Send Volume
D (141137) BT_GATT: gatt_get_ch_state: ch_state=4
I (141137) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (141137) BT_GATT: GATTS_HandleValueNotification
D (141137) BT_GATT: gatt_get_ch_state: ch_state=4
V (141147) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (141197) BT_GATT: gatt_get_ch_state: ch_state=4
I (141197) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (141197) BT_GATT: GATTS_HandleValueNotification
D (141197) BT_GATT: gatt_get_ch_state: ch_state=4
V (141207) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (143207) HID_DEV_DEMO: Send Volume
D (143207) BT_GATT: gatt_get_ch_state: ch_state=4
I (143207) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (143207) BT_GATT: GATTS_HandleValueNotification
D (143207) BT_GATT: gatt_get_ch_state: ch_state=4
V (143217) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (143267) BT_GATT: gatt_get_ch_state: ch_state=4
I (143267) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (143267) BT_GATT: GATTS_HandleValueNotification
D (143267) BT_GATT: gatt_get_ch_state: ch_state=4
V (143277) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (145277) HID_DEV_DEMO: Send Volume
D (145277) BT_GATT: gatt_get_ch_state: ch_state=4
I (145277) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (145277) BT_GATT: GATTS_HandleValueNotification
D (145277) BT_GATT: gatt_get_ch_state: ch_state=4
V (145287) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (145337) BT_GATT: gatt_get_ch_state: ch_state=4
I (145337) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (145337) BT_GATT: GATTS_HandleValueNotification
D (145337) BT_GATT: gatt_get_ch_state: ch_state=4
V (145347) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (147347) HID_DEV_DEMO: Send Volume
D (147347) BT_GATT: gatt_get_ch_state: ch_state=4
I (147347) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (147347) BT_GATT: GATTS_HandleValueNotification
D (147347) BT_GATT: gatt_get_ch_state: ch_state=4
V (147357) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (147407) BT_GATT: gatt_get_ch_state: ch_state=4
I (147407) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (147407) BT_GATT: GATTS_HandleValueNotification
D (147407) BT_GATT: gatt_get_ch_state: ch_state=4
V (147417) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (149417) HID_DEV_DEMO: Send Volume
D (149417) BT_GATT: gatt_get_ch_state: ch_state=4
I (149417) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (149417) BT_GATT: GATTS_HandleValueNotification
D (149417) BT_GATT: gatt_get_ch_state: ch_state=4
V (149427) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (149477) BT_GATT: gatt_get_ch_state: ch_state=4
I (149477) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (149477) BT_GATT: GATTS_HandleValueNotification
D (149477) BT_GATT: gatt_get_ch_state: ch_state=4
V (149487) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (151487) HID_DEV_DEMO: Send Volume
D (151487) BT_GATT: gatt_get_ch_state: ch_state=4
I (151487) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (151487) BT_GATT: GATTS_HandleValueNotification
D (151487) BT_GATT: gatt_get_ch_state: ch_state=4
V (151497) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (151547) BT_GATT: gatt_get_ch_state: ch_state=4
I (151547) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (151547) BT_GATT: GATTS_HandleValueNotification
D (151547) BT_GATT: gatt_get_ch_state: ch_state=4
V (151557) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (153557) HID_DEV_DEMO: Send Volume
D (153557) BT_GATT: gatt_get_ch_state: ch_state=4
I (153557) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (153557) BT_GATT: GATTS_HandleValueNotification
D (153557) BT_GATT: gatt_get_ch_state: ch_state=4
V (153567) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (153617) BT_GATT: gatt_get_ch_state: ch_state=4
I (153617) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (153617) BT_GATT: GATTS_HandleValueNotification
D (153617) BT_GATT: gatt_get_ch_state: ch_state=4
V (153627) BLE_HIDD: HID CONF[0] status: 0x00, len: 0

And the second that is working:

I (34197) ESP_HID_GAP: BLE GAP AUTH SUCCESS
D (34217) BT_GATT: GATT   ATT protocol channel with BDA: f8ffc2371460 is connected
D (34217) BT_GATT: gatt_is_bda_in_the_srv_chg_clt_list :f8-ff-c2-37-14-60
D (34217) BT_GATT: gatt_add_srv_chg_clt
D (34227) BT_GATT: enqueue a srv chg client
D (34227) BT_GATT: gatt_sr_init_cl_status feat 0 aware 1
D (34237) BT_GATT: gatt_set_ch_state: old=0 new=4
D (34237) BT_GATT: gatt_connect_cback: from f8ffc2371460 connected:1 conn_id=1 reason = 0x0000
D (34247) BT_GATT: gatt_get_ch_state: ch_state=4
I (34247) BT_GATT: GATT_GetConnIdIfConnected status=1
D (34257) BT_GATT: gatt_num_apps_hold_link   num=0
D (34257) BT_GATT: gatt_get_ch_state: ch_state=4
D (34267) BT_GATT: gatt_request_cback
D (34267) BT_GATT: Get MTU exchange new mtu size: 517
D (34277) BT_GAP: gap_ble_s_attr_request_cback : recv type (0x04)
D (34277) BT_GAP: Get MTU exchange new mtu size: 517
I (34287) BT_GATT: GATT_GetConnectionInfor conn_id=3
I (34297) BT_GATT: GATT_GetConnectionInfor conn_id=4
I (34297) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (34307) BT_GATT: gatt_get_ch_state: ch_state=4
D (34307) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0004 offset=0 len=2 sec_flag=0x34 key_size=16
D (34317) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
D (34327) BT_GATT: gatt_request_cback
D (34327) BT_GATT: GATTS_SetAttributeValue: attr_handle: 4  length: 2
I (34337) BT_GATT: GATTS_SendRsp: conn_id: 1  trans_id: 1  Status: 0x0000
D (34347) BT_GATT: gatt_get_ch_state: ch_state=4
D (34347) BT_GATT: gatt_sr_process_app_rsp gatt_if=1
D (34357) BT_GATT: gatt_dequeue_sr_cmd
D (34357) BT_GATT: gatt_sr_process_app_rsp ret_code=0
V (34367) BLE_HIDD: Battery CONNECT
V (34367) BLE_HIDD: Dev Info CONNECT
D (34367) BLE_HIDD: HID CONNECT[0] conn_id = 0
V (34377) BLE_HIDD: Battery MTU
V (34377) BLE_HIDD: Dev Info MTU
V (34387) BLE_HIDD: HID[0] MTU = 517
D (34387) event: running post ESP_HIDD_EVENTS:1 with handler 0x42009630 and context 0x3fcaaa4c on loop 0x3fca53a4
D (34397) event: running post ESP_HIDD_EVENTS:1 with handler 0x420083aa and context 0x3fcaaa6c on loop 0x3fca53a4
I (34407) HID_DEV_BLE: CONNECT
I (34407) HID_DEV_DEMO: Send Volume
D (34417) BT_GATT: gatt_get_ch_state: ch_state=4
D (34397) BT_GATT: gatt_get_ch_state: ch_state=4
D (34427) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (34427) BT_GATT: read_attr_value uuid=0x2a29 perm=0x1 sec_flag=0x34 offset=0 read_long=0
I (34437) BT_GATT: GATT_GetConnectionInfor conn_id=4
D (34447) BT_GATT: gatt_dequeue_sr_cmd
I (34447) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (34457) BT_GATT: GATTS_HandleValueNotification
D (34457) BT_GATT: gatt_get_ch_state: ch_state=4
V (34467) BLE_HIDD: Dev Info READ
V (34467) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (34497) BT_GATT: gatt_get_ch_state: ch_state=4
D (34497) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (34497) BT_GATT: read_attr_value uuid=0x2a25 perm=0x1 sec_flag=0x34 offset=0 read_long=0
I (34507) BT_GATT: GATT_GetConnectionInfor conn_id=4
D (34507) BT_GATT: gatt_dequeue_sr_cmd
V (34517) BLE_HIDD: Dev Info READ
D (34527) BT_GATT: gatt_get_ch_state: ch_state=4
I (34527) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (34527) BT_GATT: GATTS_HandleValueNotification
D (34537) BT_GATT: gatt_get_ch_state: ch_state=4
V (34537) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (34567) BT_GATT: gatt_get_ch_state: ch_state=4
D (34567) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (34567) BT_GATT: read_attr_value uuid=0x2a50 perm=0x1 sec_flag=0x34 offset=0 read_long=0
I (34567) BT_GATT: GATT_GetConnectionInfor conn_id=4
D (34577) BT_GATT: gatt_dequeue_sr_cmd
V (34577) BLE_HIDD: Dev Info READ
D (34627) BT_GATT: gatt_get_ch_state: ch_state=4
D (34627) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0041 offset=0 len=2 sec_flag=0x34 key_size=16
D (34637) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
I (34647) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (34647) BT_GATT: gatt_dequeue_sr_cmd
V (34657) BLE_HIDD: HID CCC[0] KEYBOARD   INPUT REPORT id: 1, Notify: On, Indicate: Off
D (34677) BT_GATT: gatt_get_ch_state: ch_state=4
D (34677) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0047 offset=0 len=2 sec_flag=0x34 key_size=16
D (34677) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
D (34687) BT_GATT: Remote device try to write with a length larger then attribute's max length
I (34697) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (34707) BT_GATT: gatt_dequeue_sr_cmd
V (34707) BLE_HIDD: HID WRITE KEYBOARD  OUTPUT REPORT id: 1, len: 2
D (34717) event: running post ESP_HIDD_EVENTS:4 with handler 0x42009630 and context 0x3fcaaa4c on loop 0x3fca53a4
D (34727) event: running post ESP_HIDD_EVENTS:4 with handler 0x420083aa and context 0x3fcaaa6c on loop 0x3fca53a4
I (34737) HID_DEV_BLE: OUTPUT[0]: KEYBOARD ID:  1, Len: 2, Data:
V (34727) ESP_HID_GAP: BLE GAP EVENT UPDATE_CONN_PARAMS
D (34737) BT_GATT: gatt_get_ch_state: ch_state=4
D (34747) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x002b offset=0 len=2 sec_flag=0x34 key_size=16
D (34757) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
I (34767) BT_GATT: GATT_GetConnectionInfor conn_id=3
D (34777) BT_GATT: gatt_dequeue_sr_cmd
I (34777) HID_DEV_BLE: 01 00
V (34787) BLE_HIDD: Battery CCC: Notify: On, Indicate: Off
D (34817) BT_GATT: gatt_get_ch_state: ch_state=4
D (34817) BT_GATT: read_attr_value uuid=0x2a19 perm=0x1 sec_flag=0x34 offset=0 read_long=0
I (34827) BT_GATT: GATT_GetConnectionInfor conn_id=3
D (34827) BT_GATT: gatt_dequeue_sr_cmd
D (34837) BLE_HIDD: Battery READ 100
D (34857) BT_GATT: gatt_get_ch_state: ch_state=4
D (34857) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0047 offset=0 len=2 sec_flag=0x34 key_size=16
D (34857) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
D (34867) BT_GATT: Remote device try to write with a length larger then attribute's max length
I (34877) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (34887) BT_GATT: gatt_dequeue_sr_cmd
V (34887) BLE_HIDD: HID WRITE KEYBOARD  OUTPUT REPORT id: 1, len: 2
D (34887) event: running post ESP_HIDD_EVENTS:4 with handler 0x42009630 and context 0x3fcaaa4c on loop 0x3fca53a4
D (34907) event: running post ESP_HIDD_EVENTS:4 with handler 0x420083aa and context 0x3fcaaa6c on loop 0x3fca53a4
I (34917) HID_DEV_BLE: OUTPUT[0]: KEYBOARD ID:  1, Len: 2, Data:
I (34917) HID_DEV_BLE: 01 00
D (34917) BT_GATT: gatt_get_ch_state: ch_state=4
D (34927) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0047 offset=0 len=2 sec_flag=0x34 key_size=16
D (34937) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
D (34947) BT_GATT: Remote device try to write with a length larger then attribute's max length
I (34957) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (34957) BT_GATT: gatt_dequeue_sr_cmd
V (34917) ESP_HID_GAP: BLE GAP EVENT UPDATE_CONN_PARAMS
V (34967) BLE_HIDD: HID WRITE KEYBOARD  OUTPUT REPORT id: 1, len: 2
D (34977) event: running post ESP_HIDD_EVENTS:4 with handler 0x42009630 and context 0x3fcaaa4c on loop 0x3fca53a4
D (34987) event: running post ESP_HIDD_EVENTS:4 with handler 0x420083aa and context 0x3fcaaa6c on loop 0x3fca53a4
I (34997) HID_DEV_BLE: OUTPUT[0]: KEYBOARD ID:  1, Len: 2, Data:
I (35007) HID_DEV_BLE: 01 00
D (35057) BT_GATT: gatt_get_ch_state: ch_state=4
D (35057) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0047 offset=0 len=2 sec_flag=0x34 key_size=16
D (35057) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
D (35067) BT_GATT: Remote device try to write with a length larger then attribute's max length
I (35077) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (35087) BT_GATT: gatt_dequeue_sr_cmd
V (35087) BLE_HIDD: HID WRITE KEYBOARD  OUTPUT REPORT id: 1, len: 2
D (35097) event: running post ESP_HIDD_EVENTS:4 with handler 0x42009630 and context 0x3fcaaa4c on loop 0x3fca53a4
D (35107) event: running post ESP_HIDD_EVENTS:4 with handler 0x420083aa and context 0x3fcaaa6c on loop 0x3fca53a4
I (35117) HID_DEV_BLE: OUTPUT[0]: KEYBOARD ID:  1, Len: 2, Data:
I (35117) HID_DEV_BLE: 01 00
D (35187) BT_GATT: gatt_get_ch_state: ch_state=4
D (35187) BT_GATT: gatts_write_attr_perm_check op_code=0x12 handle=0x0047 offset=0 len=2 sec_flag=0x34 key_size=16
D (35197) BT_GATT: gatts_write_attr_perm_check p_attr->permission =0x0011 min_key_size==0x0000
D (35207) BT_GATT: Remote device try to write with a length larger then attribute's max length
I (35217) BT_GATT: GATT_GetConnectionInfor conn_id=5
D (35217) BT_GATT: gatt_dequeue_sr_cmd
V (35227) BLE_HIDD: HID WRITE KEYBOARD  OUTPUT REPORT id: 1, len: 2
D (35227) event: running post ESP_HIDD_EVENTS:4 with handler 0x42009630 and context 0x3fcaaa4c on loop 0x3fca53a4
D (35237) event: running post ESP_HIDD_EVENTS:4 with handler 0x420083aa and context 0x3fcaaa6c on loop 0x3fca53a4
I (35247) HID_DEV_BLE: OUTPUT[0]: KEYBOARD ID:  1, Len: 2, Data:
I (35257) HID_DEV_BLE: 01 00
D (36297) BT_GATT: gatt_get_ch_state: ch_state=4
D (36307) BT_GATT: gatts_process_read_by_type_req, op_code =8, len = 0
D (36307) BT_GATT: read_attr_value uuid=0x2a00 perm=0x1 sec_flag=0x34 offset=0 read_long=0
D (36307) BT_GAP: gap_ble_s_attr_request_cback : recv type (0x01)
D (36317) BT_GAP: GATT_UUID_GAP_DEVICE_NAME len=0x000c
I (36327) BT_GATT: GATTS_SendRsp: conn_id: 2  trans_id: 13  Status: 0x0000
D (36327) BT_GATT: gatt_get_ch_state: ch_state=4
D (36337) BT_GATT: gatt_sr_process_app_rsp gatt_if=2
D (36337) BT_GATT: gatt_dequeue_sr_cmd
D (36347) BT_GATT: gatt_sr_process_app_rsp ret_code=0
I (36547) HID_DEV_DEMO: Send Volume
D (36547) BT_GATT: gatt_get_ch_state: ch_state=4
I (36547) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (36547) BT_GATT: GATTS_HandleValueNotification
D (36547) BT_GATT: gatt_get_ch_state: ch_state=4
V (36557) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (36607) BT_GATT: gatt_get_ch_state: ch_state=4
I (36607) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (36607) BT_GATT: GATTS_HandleValueNotification
D (36607) BT_GATT: gatt_get_ch_state: ch_state=4
V (36617) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (38617) HID_DEV_DEMO: Send Volume
D (38617) BT_GATT: gatt_get_ch_state: ch_state=4
I (38617) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (38617) BT_GATT: GATTS_HandleValueNotification
D (38617) BT_GATT: gatt_get_ch_state: ch_state=4
V (38627) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (38677) BT_GATT: gatt_get_ch_state: ch_state=4
I (38677) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (38677) BT_GATT: GATTS_HandleValueNotification
D (38677) BT_GATT: gatt_get_ch_state: ch_state=4
V (38687) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (40687) HID_DEV_DEMO: Send Volume
D (40687) BT_GATT: gatt_get_ch_state: ch_state=4
I (40687) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (40687) BT_GATT: GATTS_HandleValueNotification
D (40687) BT_GATT: gatt_get_ch_state: ch_state=4
V (40697) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (40747) BT_GATT: gatt_get_ch_state: ch_state=4
I (40747) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (40747) BT_GATT: GATTS_HandleValueNotification
D (40747) BT_GATT: gatt_get_ch_state: ch_state=4
V (40757) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (42757) HID_DEV_DEMO: Send Volume
D (42757) BT_GATT: gatt_get_ch_state: ch_state=4
I (42757) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (42757) BT_GATT: GATTS_HandleValueNotification
D (42757) BT_GATT: gatt_get_ch_state: ch_state=4
V (42767) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (42817) BT_GATT: gatt_get_ch_state: ch_state=4
I (42817) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (42817) BT_GATT: GATTS_HandleValueNotification
D (42817) BT_GATT: gatt_get_ch_state: ch_state=4
V (42827) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (44827) HID_DEV_DEMO: Send Volume
D (44827) BT_GATT: gatt_get_ch_state: ch_state=4
I (44827) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (44827) BT_GATT: GATTS_HandleValueNotification
D (44827) BT_GATT: gatt_get_ch_state: ch_state=4
V (44837) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (44887) BT_GATT: gatt_get_ch_state: ch_state=4
I (44887) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (44887) BT_GATT: GATTS_HandleValueNotification
D (44887) BT_GATT: gatt_get_ch_state: ch_state=4
V (44897) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (46897) HID_DEV_DEMO: Send Volume
D (46897) BT_GATT: gatt_get_ch_state: ch_state=4
I (46897) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (46897) BT_GATT: GATTS_HandleValueNotification
D (46897) BT_GATT: gatt_get_ch_state: ch_state=4
V (46907) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (46957) BT_GATT: gatt_get_ch_state: ch_state=4
I (46957) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (46957) BT_GATT: GATTS_HandleValueNotification
D (46957) BT_GATT: gatt_get_ch_state: ch_state=4
V (46967) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (48967) HID_DEV_DEMO: Send Volume
D (48967) BT_GATT: gatt_get_ch_state: ch_state=4
I (48967) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (48967) BT_GATT: GATTS_HandleValueNotification
D (48967) BT_GATT: gatt_get_ch_state: ch_state=4
V (48977) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (49027) BT_GATT: gatt_get_ch_state: ch_state=4
I (49027) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (49027) BT_GATT: GATTS_HandleValueNotification
D (49027) BT_GATT: gatt_get_ch_state: ch_state=4
V (49037) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (51037) HID_DEV_DEMO: Send Volume
D (51037) BT_GATT: gatt_get_ch_state: ch_state=4
I (51037) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (51037) BT_GATT: GATTS_HandleValueNotification
D (51037) BT_GATT: gatt_get_ch_state: ch_state=4
V (51047) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (51097) BT_GATT: gatt_get_ch_state: ch_state=4
I (51097) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (51097) BT_GATT: GATTS_HandleValueNotification
D (51097) BT_GATT: gatt_get_ch_state: ch_state=4
V (51107) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (53107) HID_DEV_DEMO: Send Volume
D (53107) BT_GATT: gatt_get_ch_state: ch_state=4
I (53107) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (53107) BT_GATT: GATTS_HandleValueNotification
D (53107) BT_GATT: gatt_get_ch_state: ch_state=4
V (53117) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (53167) BT_GATT: gatt_get_ch_state: ch_state=4
I (53167) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (53167) BT_GATT: GATTS_HandleValueNotification
D (53167) BT_GATT: gatt_get_ch_state: ch_state=4
V (53177) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (55177) HID_DEV_DEMO: Send Volume
D (55177) BT_GATT: gatt_get_ch_state: ch_state=4
I (55177) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (55177) BT_GATT: GATTS_HandleValueNotification
D (55177) BT_GATT: gatt_get_ch_state: ch_state=4
V (55187) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (55237) BT_GATT: gatt_get_ch_state: ch_state=4
I (55237) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (55237) BT_GATT: GATTS_HandleValueNotification
D (55237) BT_GATT: gatt_get_ch_state: ch_state=4
V (55247) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (57247) HID_DEV_DEMO: Send Volume
D (57247) BT_GATT: gatt_get_ch_state: ch_state=4
I (57247) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (57247) BT_GATT: GATTS_HandleValueNotification
D (57247) BT_GATT: gatt_get_ch_state: ch_state=4
V (57257) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (57307) BT_GATT: gatt_get_ch_state: ch_state=4
I (57307) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (57307) BT_GATT: GATTS_HandleValueNotification
D (57307) BT_GATT: gatt_get_ch_state: ch_state=4
V (57317) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (59317) HID_DEV_DEMO: Send Volume
D (59317) BT_GATT: gatt_get_ch_state: ch_state=4
I (59317) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (59317) BT_GATT: GATTS_HandleValueNotification
D (59317) BT_GATT: gatt_get_ch_state: ch_state=4
V (59327) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (59377) BT_GATT: gatt_get_ch_state: ch_state=4
I (59377) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (59377) BT_GATT: GATTS_HandleValueNotification
D (59377) BT_GATT: gatt_get_ch_state: ch_state=4
V (59387) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (61387) HID_DEV_DEMO: Send Volume
D (61387) BT_GATT: gatt_get_ch_state: ch_state=4
I (61387) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (61387) BT_GATT: GATTS_HandleValueNotification
D (61387) BT_GATT: gatt_get_ch_state: ch_state=4
V (61397) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
D (61447) BT_GATT: gatt_get_ch_state: ch_state=4
I (61447) BT_GATT: GATT_GetConnectionInfor conn_id=5
I (61447) BT_GATT: GATTS_HandleValueNotification
D (61447) BT_GATT: gatt_get_ch_state: ch_state=4
V (61457) BLE_HIDD: HID CONF[0] status: 0x00, len: 0
I (63457) HID_DEV_DEMO: Send Volume
D (63457) BT_GATT: gatt_get_ch_state: ch_state=4

@esp-zhp esp-zhp removed their assignment Jul 5, 2023
@jeremyherbert
Copy link
Contributor Author

I think the issue is that the code in ble_hidd.c assumes that when the GATTS is connected that GAP authentication is already complete, but when you are using a passkey the GATTS connection (ie ESP_GATTS_CONNECT_EVT) happens before GAP authentication is finished.

@jeremyherbert
Copy link
Contributor Author

This seems to be to do with encryption not being enabled on the link. I can see the following error in the mac os console:

default	11:18:35.096997+1000	BluetoothUIServer	LEHIDConnectionComplete - VID:0x16C0 PID:0x05DF “ESP BLE HID2”: no custom info found
error	11:18:35.207520+1000	BTLEServer	Not creating HID device as the link is not encrypted

@jeremyherbert
Copy link
Contributor Author

I have found a workaround (or maybe even a fix), if you edit ble_hidd.c in the esp_hid component and set all of the GATTS permissions on all of the services to ESP_GATT_PERM_READ_ENCRYPTED or ESP_GATT_PERM_READ_ENCRYPTED | ESP_GATT_PERM_WRITE_ENCRYPTED as appropriate, then the device is able to connect properly the first time, and automatic connection is working correctly through power cycles.

Since the HID over BLE standard requires encryption anyway, I don't see a problem with doing this.

@jeremyherbert
Copy link
Contributor Author

So the real solution is that both iOS and Mac require the report map characteristic and the report reference descriptor to have their permissions set as encrypted, otherwise when the initial connection occurs the device is considered not encrypted and the HID reports are not parsed and enumerated. This isn’t documented anywhere, but it is the way that they behave. The problem only appears when pairing OOB or with passkey input on the device. The battery and device info service do not need to be encrypted. On the second connection where pairing and bonding is already complete, the check is skipped because the connection is encrypted before the GATT operations.

The characteristics probably should be set as encrypted anyway, as this follows the spirit of the BLE HOGP spec requiring all HID data to be transferred over an encrypted connection.

@espressif-bot espressif-bot added Status: In Progress Work is in progress and removed Status: Opened Issue is new labels Aug 11, 2023
@esp-zhp
Copy link
Collaborator

esp-zhp commented Nov 8, 2023

In the latest version(by commit 5727802), we have addressed the issue by setting some characteristic properties to be encrypted. Thank you very much for reporting the issue.

@espressif-bot espressif-bot added Status: Done Issue is done internally Resolution: Done Issue is done internally and removed Status: In Progress Work is in progress labels Nov 8, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally Type: Bug bugs in IDF
Projects
None yet
Development

No branches or pull requests

4 participants