Bluetooth Low Energy service crash report - when trying read a HID feature report

Bluetooth Low Energy service crash report - when trying read a HID feature report

[Murat Kilivan]

Hello,

I have successfully connected to a BLE HID (peripheral) device and /dev/hidraw1 file is created. I am able to read raw data successfully from hidraw1. However, when I try to read a feature report from this device, the Bluetooth service crashes. The bluetooth service log and my source code are below.

Enviroments:
------------
Linux Mint-17 KDE
Kernel 3.13.0-24-generic
BlueZ 5.21

Output of Bluetooth service:
----------------------------
# bluetooth -d -n
...
...
bluetoothd[2610]: profiles/input/hog.c:forward_report() Sending report type 3 to device 0x000C handle 0x1C
(bluetoothd:2610): GLib-ERROR **: /build/buildd/glib2.0-2.40.0/./glib/gmem.c:103: failed to allocate 4294967295 bytes

Source code:
------------
void foo()
{
    uint8_t buf[3];
    memset(buf, 0x0, sizeof(buf));

    m_DevReadWriteHandle = open("/dev/hidraw1", O_RDWR);
...
    buf[0] = 0x04; // Feature Report ID
    ioctl(m_DevReadWriteHandle, HIDIOCGFEATURE(sizeof(buf)), buf);
}




Member of the CSR plc group of companies. CSR plc registered in England and Wales, registered number 4187346, registered office Churchill House, Cambridge Business Park, Cowley Road, Cambridge, CB4 0WZ, United Kingdom
More information can be found at www.csr.com. Keep up to date with CSR on our technical blog, www.csr.com/blog, CSR people blog, www.csr.com/people, YouTube, www.youtube.com/user/CSRplc, Facebook, www.facebook.com/pages/CSR/191038434253534, or follow us on Twitter at www.twitter.com/CSR_plc.
New for 2014, you can now access the wide range of products powered by aptX at www.aptx.com.

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Johan Hedberg]

Hi Murat,

On Wed, Jul 23, 2014, Murat Kilivan wrote:
> I have successfully connected to a BLE HID (peripheral) device and /dev/hidraw1 file is created. I am able to read raw data successfully from hidraw1. However, when I try to read a feature report from this device, the Bluetooth service crashes. The bluetooth service log and my source code are below.
> 
> Enviroments:
> ------------
> Linux Mint-17 KDE
> Kernel 3.13.0-24-generic
> BlueZ 5.21
> 
> Output of Bluetooth service:
> ----------------------------
> # bluetooth -d -n
> ...
> ...
> bluetoothd[2610]: profiles/input/hog.c:forward_report() Sending report type 3 to device 0x000C handle 0x1C
> (bluetoothd:2610): GLib-ERROR **: /build/buildd/glib2.0-2.40.0/./glib/gmem.c:103: failed to allocate 4294967295 bytes

4294967295 is the same as (uint32_t) -1 so seems like there might be a
missing error check somewhere. Could you please try to get the full
bluetoothd backtrace by running it through gdb or valgrind? If possible
do this with the latest git version.

Johan

RE: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Murat Kilivan]

-----Original Message-----
From: Johan Hedberg [mailto:johan.hedberg@gmail.com] 
Sent: 24 July 2014 09:31
To: Murat Kilivan
Cc: linux-bluetooth@vger.kernel.org
Subject: Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

Hi Murat,

Hi Johan,

On Wed, Jul 23, 2014, Murat Kilivan wrote:
> I have successfully connected to a BLE HID (peripheral) device and /dev/hidraw1 file is created. I am able to read raw data successfully from hidraw1. However, when I try to read a feature report from this device, the Bluetooth service crashes. The bluetooth service log and my source code are below.
> 
> Enviroments:
> ------------
> Linux Mint-17 KDE
> Kernel 3.13.0-24-generic
> BlueZ 5.21
> 
> Output of Bluetooth service:
> ----------------------------
> # bluetooth -d -n
> ...
> ...
> bluetoothd[2610]: profiles/input/hog.c:forward_report() Sending report 
> type 3 to device 0x000C handle 0x1C
> (bluetoothd:2610): GLib-ERROR **: 
> /build/buildd/glib2.0-2.40.0/./glib/gmem.c:103: failed to allocate 
> 4294967295 bytes

4294967295 is the same as (uint32_t) -1 so seems like there might be a missing error check somewhere. Could you please try to get the full bluetoothd backtrace by running it through gdb or valgrind? If possible do this with the latest git version.

git revision: 5a67d00d3fcfafa40cbf80de48f08768cb3b132d

murat@murat-VirtualBox:~/git/bluez >sudo valgrind --leak-check=full src/bluetoothd -d -n
...
...
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:03, rssi -61 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:09, rssi -72 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:09, rssi -71 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:06, rssi -65 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:06, rssi -65 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:01, rssi -53 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -53 delta 12
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:01, rssi -52 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:08, rssi -72 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:08, rssi -72 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:discovery_disconnect() owner :1.76
bluetoothd[10991]: src/adapter.c:discovery_destroy() owner :1.76
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:02, rssi -55 flags 0x0000 eir_len 23
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:02, rssi -55 flags 0x0000 eir_len 0
bluetoothd[10991]: src/adapter.c:stop_discovery_complete() status 0x00
bluetoothd[10991]: src/adapter.c:trigger_passive_scanning() 
bluetoothd[10991]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0
bluetoothd[10991]: src/adapter.c:start_discovery() sender :1.77
bluetoothd[10991]: src/adapter.c:trigger_start_discovery() 
bluetoothd[10991]: src/adapter.c:cancel_passive_scanning() 
bluetoothd[10991]: src/adapter.c:start_discovery_timeout() 
bluetoothd[10991]: src/adapter.c:start_discovery_complete() status 0x00
bluetoothd[10991]: src/adapter.c:discovering_callback() hci0 type 7 discovering 1
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_create() dst 00:02:5B:00:19:99
bluetoothd[10991]: src/device.c:device_new() address 00:02:5B:00:19:99
bluetoothd[10991]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_00_02_5B_00_19_99
bluetoothd[10991]: src/device.c:btd_device_set_temporary() temporary 1
bluetoothd[10991]: src/adapter.c:adapter_connect_list_remove() device /org/bluez/hci0/dev_00_02_5B_00_19_99 is not on the list, ignoring
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -51
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -55 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -51 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -52 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -52 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -52 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:04, rssi -69 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -69
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:04, rssi -69 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -52 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -52 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:07, rssi -53 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -53
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:07, rssi -52 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:03, rssi -75 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -75
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:03, rssi -74 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:05, rssi -69 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -69
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:05, rssi -69 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:09, rssi -75 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -75
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:09, rssi -74 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -52 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:01, rssi -72 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -72
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:02, rssi -61 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -61
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:02, rssi -61 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:08, rssi -68 flags 0x0000 eir_len 23
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -68
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:33:08, rssi -67 flags 0x0000 eir_len 0
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr E4:13:87:11:68:68, rssi -80 flags 0x0000 eir_len 27
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -80
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr E4:13:87:11:68:68, rssi -79 flags 0x0000 eir_len 9
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -53 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -55 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -54 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr D7:B2:49:E8:EB:7C, rssi -79 flags 0x0000 eir_len 27
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi -79
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr D7:B2:49:E8:EB:7C, rssi -78 flags 0x0000 eir_len 8
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -55 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -55 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -55 flags 0x0000 eir_len 28
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:device_found_callback() hci0 addr 00:02:5B:00:19:99, rssi -55 flags 0x0000 eir_len 3
bluetoothd[10991]: src/device.c:device_set_legacy() legacy 0
bluetoothd[10991]: src/adapter.c:discovery_disconnect() owner :1.77
bluetoothd[10991]: src/adapter.c:discovery_destroy() owner :1.77
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/device.c:device_set_rssi() rssi 0
bluetoothd[10991]: src/adapter.c:stop_discovery_complete() status 0x00
bluetoothd[10991]: src/adapter.c:trigger_passive_scanning() 
bluetoothd[10991]: src/adapter.c:discovering_callback() hci0 type 7 discovering 0
bluetoothd[10991]: src/agent.c:agent_ref() 0x4f0d478: ref=1
bluetoothd[10991]: src/agent.c:register_agent() agent :1.78
bluetoothd[10991]: src/device.c:btd_device_set_temporary() temporary 0
bluetoothd[10991]: src/agent.c:agent_ref() 0x4f0d478: ref=2
bluetoothd[10991]: src/device.c:bonding_request_new() Requesting bonding for 00:02:5B:00:19:99
bluetoothd[10991]: src/agent.c:agent_ref() 0x4f0d478: ref=3
bluetoothd[10991]: src/agent.c:agent_unref() 0x4f0d478: ref=2
bluetoothd[10991]: src/device.c:device_connect_le() Connection attempt to: 00:02:5B:00:19:99
bluetoothd[10991]: src/adapter.c:connected_callback() hci0 device 00:02:5B:00:19:99 connected eir_len 0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=1
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=2
bluetoothd[10991]: src/adapter.c:adapter_connect_list_remove() device /org/bluez/hci0/dev_00_02_5B_00_19_99 is not on the list, ignoring
bluetoothd[10991]: src/adapter.c:suspend_discovery() 
bluetoothd[10991]: src/adapter.c:adapter_bonding_attempt() hci0 bdaddr 00:02:5B:00:19:99 type 1 io_cap 0x03
bluetoothd[10991]: src/adapter.c:pair_device_complete() Success (0x00)
bluetoothd[10991]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 00:02:5B:00:19:99 type 1 status 0x0
bluetoothd[10991]: src/device.c:device_bonding_complete() bonding 0x4f34860 status 0x00
bluetoothd[10991]: src/device.c:device_bonding_complete() Proceeding with service discovery
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=3
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: src/agent.c:agent_unref() 0x4f0d478: ref=1
bluetoothd[10991]: src/adapter.c:resume_discovery() 
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/adapter.c:new_long_term_key_callback() hci0 new LTK for 00:02:5B:00:19:99 type 0 enc_size 16
bluetoothd[10991]: src/device.c:device_set_bonded() 
bluetoothd[10991]: src/device.c:device_bonding_complete() bonding (nil) status 0x00
bluetoothd[10991]: src/adapter.c:resume_discovery() 
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/device.c:primary_cb() status 0
bluetoothd[10991]: src/device.c:find_included_services() service count 5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/device.c:find_included_cb() status 0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/device.c:find_included_cb() status 0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/device.c:find_included_cb() status 0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/device.c:find_included_cb() status 0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=3
bluetoothd[10991]: src/device.c:find_included_cb() status 0
bluetoothd[10991]: src/device.c:update_gatt_services() UUID Added: 00001801-0000-1000-8000-00805f9b34fb
bluetoothd[10991]: src/device.c:update_gatt_services() UUID Added: 00001800-0000-1000-8000-00805f9b34fb
bluetoothd[10991]: src/device.c:update_gatt_services() UUID Added: 00001812-0000-1000-8000-00805f9b34fb
bluetoothd[10991]: src/device.c:update_gatt_services() UUID Added: 0000180f-0000-1000-8000-00805f9b34fb
bluetoothd[10991]: src/device.c:update_gatt_services() UUID Added: 0000180a-0000-1000-8000-00805f9b34fb
bluetoothd[10991]: src/device.c:device_probe_profiles() Probing profiles for device 00:02:5B:00:19:99
bluetoothd[10991]: src/device.c:btd_device_add_attio_callback() 0x4d74a50 registered ATT connection callback
bluetoothd[10991]: src/device.c:device_set_auto_connect() 00:02:5B:00:19:99 auto connect: 1
bluetoothd[10991]: src/device.c:device_set_auto_connect() Already connected
bluetoothd[10991]: src/service.c:change_state() 0x4fbbde8: device 00:02:5B:00:19:99 profile deviceinfo state changed: unavailable -> disconnected (0)
bluetoothd[10991]: src/device.c:btd_device_add_attio_callback() 0x4d74a50 registered ATT connection callback
bluetoothd[10991]: src/device.c:device_set_auto_connect() 00:02:5B:00:19:99 auto connect: 1
bluetoothd[10991]: src/service.c:change_state() 0x4fc4ad8: device 00:02:5B:00:19:99 profile gap-gatt-profile state changed: unavailable -> disconnected (0)
bluetoothd[10991]: profiles/input/hog.c:hog_probe() path /org/bluez/hci0/dev_00_02_5B_00_19_99
bluetoothd[10991]: src/device.c:btd_device_add_attio_callback() 0x4d74a50 registered ATT connection callback
bluetoothd[10991]: src/device.c:device_set_auto_connect() 00:02:5B:00:19:99 auto connect: 1
bluetoothd[10991]: src/service.c:change_state() 0x4fc5cd0: device 00:02:5B:00:19:99 profile input-hog state changed: unavailable -> disconnected (0)
bluetoothd[10991]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_00_02_5B_00_19_99 err 0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=2
bluetoothd[10991]: src/device.c:notify_attios() 
bluetoothd[10991]: src/device.c:attio_connected() 
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=3
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=4
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=5
bluetoothd[10991]: src/device.c:attio_connected() 
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=6
bluetoothd[10991]: profiles/gatt/gas.c:attio_connected_cb() MTU Exchange: Requesting 672
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: src/device.c:attio_connected() 
bluetoothd[10991]: profiles/input/hog.c:attio_connected_cb() HoG connected
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: src/device.c:notify_attios() 
bluetoothd[10991]: src/device.c:notify_attios() 
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: src/device.c:btd_device_set_trusted() trusted 1
bluetoothd[10991]: src/agent.c:agent_disconnect() Agent :1.78 disconnected
bluetoothd[10991]: src/agent.c:agent_destroy() agent :1.78
bluetoothd[10991]: src/agent.c:agent_unref() 0x4f0d478: ref=0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: profiles/gatt/gas.c:exchange_mtu_cb() MTU exchange succeeded: 23
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=10
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: profiles/gatt/gas.c:discover_ccc_cb() CCC: 0x0004
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=7
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=8
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x000e UUID: 00002a4a-0000-1000-8000-00805f9b34fb properties: 02
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x0010 UUID: 00002a4b-0000-1000-8000-00805f9b34fb properties: 02
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x0013 UUID: 00002a4d-0000-1000-8000-00805f9b34fb properties: 12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=10
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x0017 UUID: 00002a4d-0000-1000-8000-00805f9b34fb properties: 12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=11
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x001b UUID: 00002a4d-0000-1000-8000-00805f9b34fb properties: 0a
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=12
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x001e UUID: 00002a4d-0000-1000-8000-00805f9b34fb properties: 0e
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x0021 UUID: 00002a4d-0000-1000-8000-00805f9b34fb properties: 12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=14
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x0025 UUID: 00002a4d-0000-1000-8000-00805f9b34fb properties: 0e
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=15
bluetoothd[10991]: profiles/input/hog.c:char_discovered_cb() 0x0028 UUID: 00002a4c-0000-1000-8000-00805f9b34fb properties: 04
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=14
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=14
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: profiles/gatt/gas.c:ccc_written_cb() Service Changed indications enabled
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() Report MAP:
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 05 0c
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 a1 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 85 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 19 00
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 2a 9c 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 15 00
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 26 9c 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 10
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 00
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 c0
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 05 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 a1 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 85 03
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 a1 00
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 05 09
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 19 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 29 03
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 15 00
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 25 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 03
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 05
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 03
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 05 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 30
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 31
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 16 00 f8
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 26 ff 07
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 10
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 06
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 38
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 15 80
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 25 7f
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 06
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 c0
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 c0
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 06 00 ff
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 a1 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 85 05
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 15 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 25 04
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 b1 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 b1 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 15 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 25 04
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 91 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 91 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 12
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 91 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 15 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 25 04
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 12
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 81 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 85 06
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 75 08
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 95 14
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 09 01
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 91 02
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() 	 c0
bluetoothd[10991]: profiles/input/hog.c:report_map_read_cb() DIS information: vendor_src=0x0, vendor=0x0, product=0x0, version=0x0
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=13
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=11
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=12
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=11
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=10
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=11
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=10
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=10
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=9
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=7
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=8
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=7
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=6
bluetoothd[10991]: profiles/input/hog.c:info_read_cb() bcdHID: 0x0213 bCountryCode: 0x40 Flags: 0x01
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=5
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=6
bluetoothd[10991]: profiles/input/hog.c:external_report_reference_cb() External report reference read, external report characteristic UUID: 0x192a
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_ccc_written_cb() Report characteristic descriptor written: notifications enabled
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_reference_cb() Report ID: 0x01 Report type: 0x01
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_ccc_written_cb() Report characteristic descriptor written: notifications enabled
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_reference_cb() Report ID: 0x03 Report type: 0x01
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_reference_cb() Report ID: 0x05 Report type: 0x03
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_reference_cb() Report ID: 0x05 Report type: 0x02
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_ccc_written_cb() Report characteristic descriptor written: notifications enabled
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_reference_cb() Report ID: 0x05 Report type: 0x01
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: attrib/gattrib.c:g_attrib_ref() 0x4f3d998: ref=7
bluetoothd[10991]: profiles/input/hog.c:report_reference_cb() Report ID: 0x06 Report type: 0x02
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=6
bluetoothd[10991]: profiles/input/hog.c:external_service_char_cb() Discover external service characteristic failed: Invalid handle
bluetoothd[10991]: attrib/gattrib.c:g_attrib_unref() 0x4f3d998: ref=5
bluetoothd[10991]: src/attrib-server.c:channel_handler() op 0x1b
bluetoothd[10991]: profiles/input/hog.c:report_value_cb() HoG report (3 bytes)
bluetoothd[10991]: src/attrib-server.c:channel_handler() op 0x1b
bluetoothd[10991]: profiles/input/hog.c:report_value_cb() HoG report (3 bytes)
bluetoothd[10991]: profiles/input/hog.c:forward_report() Sending report type 3 to device 0x000C handle 0x1C
==10991== Warning: silly arg (-1) to malloc()

(bluetoothd:10991): GLib-ERROR **: /build/buildd/glib2.0-2.40.0/./glib/gmem.c:103: failed to allocate 4294967295 bytes
==10991== 
==10991== Process terminating with default action of signal 5 (SIGTRAP)
==10991==    at 0x40A340A: g_logv (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==    by 0x40A3522: g_log (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==    by 0x40A1C1D: g_malloc (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==    by 0x40B9E75: g_memdup (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==    by 0x80781C5: gatt_write_char (gatt.c:900)
==10991==    by 0x8072A7B: forward_report (hog.c:368)
==10991==    by 0x80A5B0D: queue_foreach (queue.c:206)
==10991==    by 0x807208E: uhid_read_handler (uhid.c:98)
==10991==    by 0x80A53F2: read_callback (io-glib.c:168)
==10991==    by 0x40E1E04: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==    by 0x409C0A6: g_main_context_dispatch (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==    by 0x409C467: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991== Invalid free() / delete / delete[] / realloc()
==10991==    at 0x402B3D8: free (in /usr/lib/valgrind/vgpreload_memcheck-x86-linux.so)
==10991==    by 0x4304F54: __libc_freeres (in /lib/i386-linux-gnu/libc-2.19.so)
==10991==    by 0x4024526: _vgnU_freeres (in /usr/lib/valgrind/vgpreload_core-x86-linux.so)
==10991==    by 0x40E4F6D: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
==10991==  Address 0xffffffff is not stack'd, malloc'd or (recently) free'd
==10991== 
==10991== 
==10991== HEAP SUMMARY:
==10991==     in use at exit: 88,721 bytes in 1,435 blocks
==10991==   total heap usage: 25,247 allocs, 23,813 frees, 13,746,560 bytes allocated
==10991== 
==10991== LEAK SUMMARY:
==10991==    definitely lost: 0 bytes in 0 blocks
==10991==    indirectly lost: 0 bytes in 0 blocks
==10991==      possibly lost: 0 bytes in 0 blocks
==10991==    still reachable: 88,721 bytes in 1,435 blocks
==10991==         suppressed: 0 bytes in 0 blocks
==10991== Reachable blocks (those to which a pointer was found) are not shown.
==10991== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==10991== 
==10991== For counts of detected and suppressed errors, rerun with: -v
==10991== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)


Murat

Johan


 To report this email as spam click https://www.mailcontrol.com/sr/MZbqvYs5QwJvpeaetUwhCQ== .


Member of the CSR plc group of companies. CSR plc registered in England and Wales, registered number 4187346, registered office Churchill House, Cambridge Business Park, Cowley Road, Cambridge, CB4 0WZ, United Kingdom
More information can be found at www.csr.com. Keep up to date with CSR on our technical blog, www.csr.com/blog, CSR people blog, www.csr.com/people, YouTube, www.youtube.com/user/CSRplc, Facebook, www.facebook.com/pages/CSR/191038434253534, or follow us on Twitter at www.twitter.com/CSR_plc.
New for 2014, you can now access the wide range of products powered by aptX at www.aptx.com.

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Johan Hedberg]

Hi Murat,

On Thu, Jul 24, 2014, Murat Kilivan wrote:
> ==10991== Process terminating with default action of signal 5 (SIGTRAP)
> ==10991==    at 0x40A340A: g_logv (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x40A3522: g_log (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x40A1C1D: g_malloc (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x40B9E75: g_memdup (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x80781C5: gatt_write_char (gatt.c:900)
> ==10991==    by 0x8072A7B: forward_report (hog.c:368)
> ==10991==    by 0x80A5B0D: queue_foreach (queue.c:206)
> ==10991==    by 0x807208E: uhid_read_handler (uhid.c:98)
> ==10991==    by 0x80A53F2: read_callback (io-glib.c:168)
> ==10991==    by 0x40E1E04: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x409C0A6: g_main_context_dispatch (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x409C467: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991== Invalid free() / delete / delete[] / realloc()
> ==10991==    at 0x402B3D8: free (in /usr/lib/valgrind/vgpreload_memcheck-x86-linux.so)
> ==10991==    by 0x4304F54: __libc_freeres (in /lib/i386-linux-gnu/libc-2.19.so)
> ==10991==    by 0x4024526: _vgnU_freeres (in /usr/lib/valgrind/vgpreload_core-x86-linux.so)
> ==10991==    by 0x40E4F6D: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==  Address 0xffffffff is not stack'd, malloc'd or (recently) free'd

This helps a lot. Thanks. I'd bet the following code from forward_report() is
responsible:

        if (hogdev->has_report_id) {
                data = ev->u.output.data + 1;
                size = ev->u.output.size - 1;
        } else {
                data = ev->u.output.data;
                size = ev->u.output.size;
        }

You could add some debug logs there to be completely certain, but I have
a feeling the first branch is taken and ev->u.output.size is 0, giving
us the "0 - 1" value which you see in the failed memory allocation.

Now the question is what the right fix is. Should the if-statement
instead be as follows:

	if (hogdev->has_report_id && ev->u.output.size > 0)
		...

Could you try modifying your code base to verify that this is indeed the
cause of the crash? Thanks.

Johan

RE: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Murat Kilivan]

-----Original Message-----
From: Johan Hedberg [mailto:johan.hedberg@gmail.com] 
Sent: 24 July 2014 11:08
To: Murat Kilivan
Cc: linux-bluetooth@vger.kernel.org
Subject: Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

Hi Murat,

Hi Johan,

On Thu, Jul 24, 2014, Murat Kilivan wrote:
> ==10991== Process terminating with default action of signal 5 (SIGTRAP)
> ==10991==    at 0x40A340A: g_logv (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x40A3522: g_log (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x40A1C1D: g_malloc (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x40B9E75: g_memdup (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x80781C5: gatt_write_char (gatt.c:900)
> ==10991==    by 0x8072A7B: forward_report (hog.c:368)
> ==10991==    by 0x80A5B0D: queue_foreach (queue.c:206)
> ==10991==    by 0x807208E: uhid_read_handler (uhid.c:98)
> ==10991==    by 0x80A53F2: read_callback (io-glib.c:168)
> ==10991==    by 0x40E1E04: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x409C0A6: g_main_context_dispatch (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==    by 0x409C467: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991== Invalid free() / delete / delete[] / realloc()
> ==10991==    at 0x402B3D8: free (in /usr/lib/valgrind/vgpreload_memcheck-x86-linux.so)
> ==10991==    by 0x4304F54: __libc_freeres (in /lib/i386-linux-gnu/libc-2.19.so)
> ==10991==    by 0x4024526: _vgnU_freeres (in /usr/lib/valgrind/vgpreload_core-x86-linux.so)
> ==10991==    by 0x40E4F6D: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
> ==10991==  Address 0xffffffff is not stack'd, malloc'd or (recently) 
> free'd

This helps a lot. Thanks. I'd bet the following code from forward_report() is
responsible:

        if (hogdev->has_report_id) {
                data = ev->u.output.data + 1;
                size = ev->u.output.size - 1;
        } else {
                data = ev->u.output.data;
                size = ev->u.output.size;
        }

You could add some debug logs there to be completely certain, but I have a feeling the first branch is taken and ev->u.output.size is 0, giving us the "0 - 1" value which you see in the failed memory allocation.

Now the question is what the right fix is. Should the if-statement instead be as follows:

	if (hogdev->has_report_id && ev->u.output.size > 0)
		...

Could you try modifying your code base to verify that this is indeed the cause of the crash? Thanks.

I added debug message to print value of ev->u.output.size and you are right, the value is zero. And then I changed if-statement as you mention. Now service is not crashes but ioct() returned -1.

Here is the log output:
bluetoothd[11554]: profiles/input/hog.c:forward_report() ev->u.output.size = 0
bluetoothd[11554]: profiles/input/hog.c:forward_report() Sending report type 3 to device 0x000C handle 0x1C
bluetoothd[11554]: attrib/gattrib.c:g_attrib_ref() 0x539d090: ref=6
bluetoothd[11554]: attrib/gattrib.c:g_attrib_unref() 0x539d090: ref=5

Murat

Johan


 To report this email as spam click https://www.mailcontrol.com/sr/MZbqvYs5QwJvpeaetUwhCQ== .


Member of the CSR plc group of companies. CSR plc registered in England and Wales, registered number 4187346, registered office Churchill House, Cambridge Business Park, Cowley Road, Cambridge, CB4 0WZ, United Kingdom
More information can be found at www.csr.com. Keep up to date with CSR on our technical blog, www.csr.com/blog, CSR people blog, www.csr.com/people, YouTube, www.youtube.com/user/CSRplc, Facebook, www.facebook.com/pages/CSR/191038434253534, or follow us on Twitter at www.twitter.com/CSR_plc.
New for 2014, you can now access the wide range of products powered by aptX at www.aptx.com.

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[David Herrmann]

Hi

On Thu, Jul 24, 2014 at 12:08 PM, Johan Hedberg <johan.hedberg@gmail.com> wrote:
> Hi Murat,
>
> On Thu, Jul 24, 2014, Murat Kilivan wrote:
>> ==10991== Process terminating with default action of signal 5 (SIGTRAP)
>> ==10991==    at 0x40A340A: g_logv (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==    by 0x40A3522: g_log (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==    by 0x40A1C1D: g_malloc (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==    by 0x40B9E75: g_memdup (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==    by 0x80781C5: gatt_write_char (gatt.c:900)
>> ==10991==    by 0x8072A7B: forward_report (hog.c:368)
>> ==10991==    by 0x80A5B0D: queue_foreach (queue.c:206)
>> ==10991==    by 0x807208E: uhid_read_handler (uhid.c:98)
>> ==10991==    by 0x80A53F2: read_callback (io-glib.c:168)
>> ==10991==    by 0x40E1E04: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==    by 0x409C0A6: g_main_context_dispatch (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==    by 0x409C467: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991== Invalid free() / delete / delete[] / realloc()
>> ==10991==    at 0x402B3D8: free (in /usr/lib/valgrind/vgpreload_memcheck-x86-linux.so)
>> ==10991==    by 0x4304F54: __libc_freeres (in /lib/i386-linux-gnu/libc-2.19.so)
>> ==10991==    by 0x4024526: _vgnU_freeres (in /usr/lib/valgrind/vgpreload_core-x86-linux.so)
>> ==10991==    by 0x40E4F6D: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>> ==10991==  Address 0xffffffff is not stack'd, malloc'd or (recently) free'd
>
> This helps a lot. Thanks. I'd bet the following code from forward_report() is
> responsible:
>
>         if (hogdev->has_report_id) {
>                 data = ev->u.output.data + 1;
>                 size = ev->u.output.size - 1;
>         } else {
>                 data = ev->u.output.data;
>                 size = ev->u.output.size;
>         }

The kernel bails out if size==0, so this never happens. The bt_uhid_*
helpers are fine, however, hog.c forward_report() is totally broken.
You use:

bt_uhid_register(hogdev->uhid, UHID_OUTPUT, forward_report, hogdev);
bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);

Therefore, you register *THE SAME* handler for UHID_OUTPUT *AND*
UHID_FEATURE. However, in forward_report() you access ev->u.output,
but this is only valid for UHID_OUTPUT. If you get a UHID_FEATURE
report you must never access anything but ev->u.feature!

Furthermore, if you receive UHID_FEATURE, the kernel blocks until you
send the answer as UHID_FEATURE_ANSWER. I really recommend dropping
this line:
    bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);

Add it again once you implemented UHID_FEATURE properly. Currently,
it's totally broken.

Thanks
David

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Johan Hedberg]

Hi David,

On Thu, Jul 24, 2014, David Herrmann wrote:
> > This helps a lot. Thanks. I'd bet the following code from forward_report() is
> > responsible:
> >
> >         if (hogdev->has_report_id) {
> >                 data = ev->u.output.data + 1;
> >                 size = ev->u.output.size - 1;
> >         } else {
> >                 data = ev->u.output.data;
> >                 size = ev->u.output.size;
> >         }
> 
> The kernel bails out if size==0, so this never happens. The bt_uhid_*
> helpers are fine, however, hog.c forward_report() is totally broken.
> You use:
> 
> bt_uhid_register(hogdev->uhid, UHID_OUTPUT, forward_report, hogdev);
> bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);
> 
> Therefore, you register *THE SAME* handler for UHID_OUTPUT *AND*
> UHID_FEATURE. However, in forward_report() you access ev->u.output,
> but this is only valid for UHID_OUTPUT. If you get a UHID_FEATURE
> report you must never access anything but ev->u.feature!
> 
> Furthermore, if you receive UHID_FEATURE, the kernel blocks until you
> send the answer as UHID_FEATURE_ANSWER. I really recommend dropping
> this line:
>     bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);
> 
> Add it again once you implemented UHID_FEATURE properly. Currently,
> it's totally broken.

Thanks a lot for the analysis! I've now pushed a patch to remove the
broken attempt at UHID_FEATURE support.

Johan

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Luiz Augusto von Dentz]

Hi David,

On Thu, Jul 24, 2014 at 6:12 PM, David Herrmann <dh.herrmann@gmail.com> wrote:
> Hi
>
> On Thu, Jul 24, 2014 at 12:08 PM, Johan Hedberg <johan.hedberg@gmail.com> wrote:
>> Hi Murat,
>>
>> On Thu, Jul 24, 2014, Murat Kilivan wrote:
>>> ==10991== Process terminating with default action of signal 5 (SIGTRAP)
>>> ==10991==    at 0x40A340A: g_logv (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==    by 0x40A3522: g_log (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==    by 0x40A1C1D: g_malloc (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==    by 0x40B9E75: g_memdup (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==    by 0x80781C5: gatt_write_char (gatt.c:900)
>>> ==10991==    by 0x8072A7B: forward_report (hog.c:368)
>>> ==10991==    by 0x80A5B0D: queue_foreach (queue.c:206)
>>> ==10991==    by 0x807208E: uhid_read_handler (uhid.c:98)
>>> ==10991==    by 0x80A53F2: read_callback (io-glib.c:168)
>>> ==10991==    by 0x40E1E04: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==    by 0x409C0A6: g_main_context_dispatch (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==    by 0x409C467: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991== Invalid free() / delete / delete[] / realloc()
>>> ==10991==    at 0x402B3D8: free (in /usr/lib/valgrind/vgpreload_memcheck-x86-linux.so)
>>> ==10991==    by 0x4304F54: __libc_freeres (in /lib/i386-linux-gnu/libc-2.19.so)
>>> ==10991==    by 0x4024526: _vgnU_freeres (in /usr/lib/valgrind/vgpreload_core-x86-linux.so)
>>> ==10991==    by 0x40E4F6D: ??? (in /lib/i386-linux-gnu/libglib-2.0.so.0.4000.0)
>>> ==10991==  Address 0xffffffff is not stack'd, malloc'd or (recently) free'd
>>
>> This helps a lot. Thanks. I'd bet the following code from forward_report() is
>> responsible:
>>
>>         if (hogdev->has_report_id) {
>>                 data = ev->u.output.data + 1;
>>                 size = ev->u.output.size - 1;
>>         } else {
>>                 data = ev->u.output.data;
>>                 size = ev->u.output.size;
>>         }
>
> The kernel bails out if size==0, so this never happens. The bt_uhid_*
> helpers are fine, however, hog.c forward_report() is totally broken.
> You use:
>
> bt_uhid_register(hogdev->uhid, UHID_OUTPUT, forward_report, hogdev);
> bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);
>
> Therefore, you register *THE SAME* handler for UHID_OUTPUT *AND*
> UHID_FEATURE. However, in forward_report() you access ev->u.output,
> but this is only valid for UHID_OUTPUT. If you get a UHID_FEATURE
> report you must never access anything but ev->u.feature!

Does the ev->u.features structure matches HID protocol, can I send as
it is or do I need to reformat it?

> Furthermore, if you receive UHID_FEATURE, the kernel blocks until you
> send the answer as UHID_FEATURE_ANSWER.

So if I got this right in addition to send the request we should
process the response as UHID_FEATURE_ANSWER otherwise it will block
other events?

-- 
Luiz Augusto von Dentz

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[David Herrmann]

Hi

>> The kernel bails out if size==0, so this never happens. The bt_uhid_*
>> helpers are fine, however, hog.c forward_report() is totally broken.
>> You use:
>>
>> bt_uhid_register(hogdev->uhid, UHID_OUTPUT, forward_report, hogdev);
>> bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);
>>
>> Therefore, you register *THE SAME* handler for UHID_OUTPUT *AND*
>> UHID_FEATURE. However, in forward_report() you access ev->u.output,
>> but this is only valid for UHID_OUTPUT. If you get a UHID_FEATURE
>> report you must never access anything but ev->u.feature!
>
> Does the ev->u.features structure matches HID protocol, can I send as
> it is or do I need to reformat it?

The uhid.h header includes these definitions:

struct uhid_feature_req {
        __u32 id;
        __u8 rnum;
        __u8 rtype;
} __attribute__((__packed__));

struct uhid_feature_answer_req {
        __u32 id;
        __u16 err;
        __u16 size;
        __u8 data[UHID_DATA_MAX];
} __attribute__((__packed__));

>> Furthermore, if you receive UHID_FEATURE, the kernel blocks until you
>> send the answer as UHID_FEATURE_ANSWER.
>
> So if I got this right in addition to send the request we should
> process the response as UHID_FEATURE_ANSWER otherwise it will block
> other events?

Kernel HID drivers can use a kernel-internal function to query an
HID-feature. This call is blocking and waits for the answer from the
device. uhid copied that design to avoid rewriting all drivers.
Therefore, IFF you get an UHID_FEATURE event, you have to send the
feature request to the device, somewhere store the context, and once
the device answers you have to find that context again and write the
answer via UHID_FEATURE_ANSWER to the kernel. The "id" field in
uhid_feature_req and uhid_feature_answer_req must match and are used
for context-tracking.

Note that this is only used for HID drivers that require synchronous
feature queries. All other drivers use UHID_OUTPUT for all outoing
reports. The "rtype" field specifies whether it's an INPUT, OUTPUT or
FEATURE report that has to be written. It it thus totally ok to ignore
UHID_FEATURE as only few drivers use it.

Note that the uhid interface so far is a bit crappy. My TODO list
contains "cleanup uhid API" but so far I haven't found the time for
it, sorry.

Thanks
David

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Luiz Augusto von Dentz]

Hi David, Murat,

On Mon, Jul 28, 2014 at 11:53 AM, David Herrmann <dh.herrmann@gmail.com> wrote:
> Hi
>
>>> The kernel bails out if size==0, so this never happens. The bt_uhid_*
>>> helpers are fine, however, hog.c forward_report() is totally broken.
>>> You use:
>>>
>>> bt_uhid_register(hogdev->uhid, UHID_OUTPUT, forward_report, hogdev);
>>> bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);
>>>
>>> Therefore, you register *THE SAME* handler for UHID_OUTPUT *AND*
>>> UHID_FEATURE. However, in forward_report() you access ev->u.output,
>>> but this is only valid for UHID_OUTPUT. If you get a UHID_FEATURE
>>> report you must never access anything but ev->u.feature!
>>
>> Does the ev->u.features structure matches HID protocol, can I send as
>> it is or do I need to reformat it?
>
> The uhid.h header includes these definitions:
>
> struct uhid_feature_req {
>         __u32 id;
>         __u8 rnum;
>         __u8 rtype;
> } __attribute__((__packed__));
>
> struct uhid_feature_answer_req {
>         __u32 id;
>         __u16 err;
>         __u16 size;
>         __u8 data[UHID_DATA_MAX];
> } __attribute__((__packed__));

That I got it, what I was asking was if that is the exact same format
used in HID so that I could sent as it is to the remote device. Im
afraid the answer is no because id and some other fields seems to be
just for context tracking as you mention bellow.

>>> Furthermore, if you receive UHID_FEATURE, the kernel blocks until you
>>> send the answer as UHID_FEATURE_ANSWER.
>>
>> So if I got this right in addition to send the request we should
>> process the response as UHID_FEATURE_ANSWER otherwise it will block
>> other events?
>
> Kernel HID drivers can use a kernel-internal function to query an
> HID-feature. This call is blocking and waits for the answer from the
> device. uhid copied that design to avoid rewriting all drivers.
> Therefore, IFF you get an UHID_FEATURE event, you have to send the
> feature request to the device, somewhere store the context, and once
> the device answers you have to find that context again and write the
> answer via UHID_FEATURE_ANSWER to the kernel. The "id" field in
> uhid_feature_req and uhid_feature_answer_req must match and are used
> for context-tracking.
>
> Note that this is only used for HID drivers that require synchronous
> feature queries. All other drivers use UHID_OUTPUT for all outoing
> reports. The "rtype" field specifies whether it's an INPUT, OUTPUT or
> FEATURE report that has to be written. It it thus totally ok to ignore
> UHID_FEATURE as only few drivers use it.

@Murat, I guess your input is needed here, why are you using
UHID_FEATURE instead of UHID_OUTPUT? Can we drop UHID_FEATURE or your
driver really requires it?

> Note that the uhid interface so far is a bit crappy. My TODO list
> contains "cleanup uhid API" but so far I haven't found the time for
> it, sorry.

No problem, our HoG plugin needs a little bit of cleanup as well.


-- 
Luiz Augusto von Dentz

RE: <COMMERCIAL>: Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[Murat Kilivan]

PkhpIERhdmlkLCBNdXJhdCwNCg0KSGkgTHVpeiwNCg0KPg0KPk9uIE1vbiwg
SnVsIDI4LCAyMDE0IGF0IDExOjUzIEFNLCBEYXZpZCBIZXJybWFubiA8ZGgu
aGVycm1hbm5AZ21haWwuY29tPiB3cm90ZToNCj4+IEhpDQo+Pg0KPj4+PiBU
aGUga2VybmVsIGJhaWxzIG91dCBpZiBzaXplPT0wLCBzbyB0aGlzIG5ldmVy
IGhhcHBlbnMuIFRoZSANCj4+Pj4gYnRfdWhpZF8qIGhlbHBlcnMgYXJlIGZp
bmUsIGhvd2V2ZXIsIGhvZy5jIGZvcndhcmRfcmVwb3J0KCkgaXMgdG90YWxs
eSBicm9rZW4uDQo+Pj4+IFlvdSB1c2U6DQo+Pj4+DQo+Pj4+IGJ0X3VoaWRf
cmVnaXN0ZXIoaG9nZGV2LT51aGlkLCBVSElEX09VVFBVVCwgZm9yd2FyZF9y
ZXBvcnQsIGhvZ2Rldik7IA0KPj4+PiBidF91aGlkX3JlZ2lzdGVyKGhvZ2Rl
di0+dWhpZCwgVUhJRF9GRUFUVVJFLCBmb3J3YXJkX3JlcG9ydCwgDQo+Pj4+
IGhvZ2Rldik7DQo+Pj4+DQo+Pj4+IFRoZXJlZm9yZSwgeW91IHJlZ2lzdGVy
ICpUSEUgU0FNRSogaGFuZGxlciBmb3IgVUhJRF9PVVRQVVQgKkFORCogDQo+
Pj4+IFVISURfRkVBVFVSRS4gSG93ZXZlciwgaW4gZm9yd2FyZF9yZXBvcnQo
KSB5b3UgYWNjZXNzIGV2LT51Lm91dHB1dCwgDQo+Pj4+IGJ1dCB0aGlzIGlz
IG9ubHkgdmFsaWQgZm9yIFVISURfT1VUUFVULiBJZiB5b3UgZ2V0IGEgVUhJ
RF9GRUFUVVJFIA0KPj4+PiByZXBvcnQgeW91IG11c3QgbmV2ZXIgYWNjZXNz
IGFueXRoaW5nIGJ1dCBldi0+dS5mZWF0dXJlIQ0KPj4+DQo+Pj4gRG9lcyB0
aGUgZXYtPnUuZmVhdHVyZXMgc3RydWN0dXJlIG1hdGNoZXMgSElEIHByb3Rv
Y29sLCBjYW4gSSBzZW5kIGFzIA0KPj4+IGl0IGlzIG9yIGRvIEkgbmVlZCB0
byByZWZvcm1hdCBpdD8NCj4+DQo+PiBUaGUgdWhpZC5oIGhlYWRlciBpbmNs
dWRlcyB0aGVzZSBkZWZpbml0aW9uczoNCj4+DQo+PiBzdHJ1Y3QgdWhpZF9m
ZWF0dXJlX3JlcSB7DQo+PiAgICAgICAgIF9fdTMyIGlkOw0KPj4gICAgICAg
ICBfX3U4IHJudW07DQo+PiAgICAgICAgIF9fdTggcnR5cGU7DQo+PiB9IF9f
YXR0cmlidXRlX18oKF9fcGFja2VkX18pKTsNCj4+DQo+PiBzdHJ1Y3QgdWhp
ZF9mZWF0dXJlX2Fuc3dlcl9yZXEgew0KPj4gICAgICAgICBfX3UzMiBpZDsN
Cj4+ICAgICAgICAgX191MTYgZXJyOw0KPj4gICAgICAgICBfX3UxNiBzaXpl
Ow0KPj4gICAgICAgICBfX3U4IGRhdGFbVUhJRF9EQVRBX01BWF07DQo+PiB9
IF9fYXR0cmlidXRlX18oKF9fcGFja2VkX18pKTsNCj4NCj5UaGF0IEkgZ290
IGl0LCB3aGF0IEkgd2FzIGFza2luZyB3YXMgaWYgdGhhdCBpcyB0aGUgZXhh
Y3Qgc2FtZSBmb3JtYXQgdXNlZCBpbiBISUQgc28gdGhhdCBJIGNvdWxkIHNl
bnQgYXMgaXQgaXMgdG8gdGhlIHJlbW90ZSBkZXZpY2UuIEltIGFmcmFpZCB0
aGUgYW5zd2VyIGlzIG5vIGJlY2F1c2UgaWQgYW5kIHNvbWUgb3RoZXIgZmll
bGRzIHNlZW1zIHRvIGJlIGp1c3QgZm9yIGNvbnRleHQgdHJhY2tpbmcgYXMg
eW91IG1lbnRpb24gYmVsbG93Lg0KPg0KPj4+PiBGdXJ0aGVybW9yZSwgaWYg
eW91IHJlY2VpdmUgVUhJRF9GRUFUVVJFLCB0aGUga2VybmVsIGJsb2NrcyB1
bnRpbCANCj4+Pj4geW91IHNlbmQgdGhlIGFuc3dlciBhcyBVSElEX0ZFQVRV
UkVfQU5TV0VSLg0KPj4+DQo+Pj4gU28gaWYgSSBnb3QgdGhpcyByaWdodCBp
biBhZGRpdGlvbiB0byBzZW5kIHRoZSByZXF1ZXN0IHdlIHNob3VsZCANCj4+
PiBwcm9jZXNzIHRoZSByZXNwb25zZSBhcyBVSElEX0ZFQVRVUkVfQU5TV0VS
IG90aGVyd2lzZSBpdCB3aWxsIGJsb2NrIA0KPj4+IG90aGVyIGV2ZW50cz8N
Cj4+DQo+PiBLZXJuZWwgSElEIGRyaXZlcnMgY2FuIHVzZSBhIGtlcm5lbC1p
bnRlcm5hbCBmdW5jdGlvbiB0byBxdWVyeSBhbiANCj4+IEhJRC1mZWF0dXJl
LiBUaGlzIGNhbGwgaXMgYmxvY2tpbmcgYW5kIHdhaXRzIGZvciB0aGUgYW5z
d2VyIGZyb20gdGhlIA0KPj4gZGV2aWNlLiB1aGlkIGNvcGllZCB0aGF0IGRl
c2lnbiB0byBhdm9pZCByZXdyaXRpbmcgYWxsIGRyaXZlcnMuDQo+PiBUaGVy
ZWZvcmUsIElGRiB5b3UgZ2V0IGFuIFVISURfRkVBVFVSRSBldmVudCwgeW91
IGhhdmUgdG8gc2VuZCB0aGUgDQo+PiBmZWF0dXJlIHJlcXVlc3QgdG8gdGhl
IGRldmljZSwgc29tZXdoZXJlIHN0b3JlIHRoZSBjb250ZXh0LCBhbmQgb25j
ZSANCj4+IHRoZSBkZXZpY2UgYW5zd2VycyB5b3UgaGF2ZSB0byBmaW5kIHRo
YXQgY29udGV4dCBhZ2FpbiBhbmQgd3JpdGUgdGhlIA0KPj4gYW5zd2VyIHZp
YSBVSElEX0ZFQVRVUkVfQU5TV0VSIHRvIHRoZSBrZXJuZWwuIFRoZSAiaWQi
IGZpZWxkIGluIA0KPj4gdWhpZF9mZWF0dXJlX3JlcSBhbmQgdWhpZF9mZWF0
dXJlX2Fuc3dlcl9yZXEgbXVzdCBtYXRjaCBhbmQgYXJlIHVzZWQgDQo+PiBm
b3IgY29udGV4dC10cmFja2luZy4NCj4+DQo+PiBOb3RlIHRoYXQgdGhpcyBp
cyBvbmx5IHVzZWQgZm9yIEhJRCBkcml2ZXJzIHRoYXQgcmVxdWlyZSBzeW5j
aHJvbm91cyANCj4+IGZlYXR1cmUgcXVlcmllcy4gQWxsIG90aGVyIGRyaXZl
cnMgdXNlIFVISURfT1VUUFVUIGZvciBhbGwgb3V0b2luZyANCj4+IHJlcG9y
dHMuIFRoZSAicnR5cGUiIGZpZWxkIHNwZWNpZmllcyB3aGV0aGVyIGl0J3Mg
YW4gSU5QVVQsIE9VVFBVVCBvciANCj4+IEZFQVRVUkUgcmVwb3J0IHRoYXQg
aGFzIHRvIGJlIHdyaXR0ZW4uIEl0IGl0IHRodXMgdG90YWxseSBvayB0byBp
Z25vcmUgDQo+PiBVSElEX0ZFQVRVUkUgYXMgb25seSBmZXcgZHJpdmVycyB1
c2UgaXQuDQo+DQo+QE11cmF0LCBJIGd1ZXNzIHlvdXIgaW5wdXQgaXMgbmVl
ZGVkIGhlcmUsIHdoeSBhcmUgeW91IHVzaW5nIFVISURfRkVBVFVSRSBpbnN0
ZWFkIG9mIFVISURfT1VUUFVUPyBDYW4gd2UgZHJvcCBVSElEX0ZFQVRVUkUg
b3IgeW91ciBkcml2ZXIgcmVhbGx5IHJlcXVpcmVzIGl0Pw0KDQpUaGUgZGV2
aWNlIHdoaWNoIEkgdHJpZWQgdG8gcmVhZCBmZWF0dXJlIHJlcG9ydCBoYXMg
Y29uZmlndXJhdGlvbiBpbmZvcm1hdGlvbiAoRm9yIGV4YW1wbGUsIHNvZnR3
YXJlIGZlYXR1cmUsIGZpcm13YXJlIHZlcnNpb24gYW5kIHNvIGZvcnRoKS4g
VGhpcyBkYXRhIGlzIG5vdCBhdmFpbGFibGUgb3ZlciBVSElEX09VVFBVVC4g
QWNjb3JkaW5nIHRvIHRoZSBVU0Igc3BlY2lmaWNhdGlvbiwgc2VjdGlvbiA2
LjIuMi41LCB0aGlzIGtpbmQgb2YgZGF0YSBpcyBkZXNjcmliZWQgJ0ZlYXR1
cmUgSXRlbXMnLiANCg0KPg0KPj4gTm90ZSB0aGF0IHRoZSB1aGlkIGludGVy
ZmFjZSBzbyBmYXIgaXMgYSBiaXQgY3JhcHB5LiBNeSBUT0RPIGxpc3QgDQo+
PiBjb250YWlucyAiY2xlYW51cCB1aGlkIEFQSSIgYnV0IHNvIGZhciBJIGhh
dmVuJ3QgZm91bmQgdGhlIHRpbWUgZm9yIA0KPj4gaXQsIHNvcnJ5Lg0KPg0K
Pk5vIHByb2JsZW0sIG91ciBIb0cgcGx1Z2luIG5lZWRzIGEgbGl0dGxlIGJp
dCBvZiBjbGVhbnVwIGFzIHdlbGwuDQoNCk11cmF0DQoKCk1lbWJlciBvZiB0
aGUgQ1NSIHBsYyBncm91cCBvZiBjb21wYW5pZXMuIENTUiBwbGMgcmVnaXN0
ZXJlZCBpbiBFbmdsYW5kIGFuZCBXYWxlcywgcmVnaXN0ZXJlZCBudW1iZXIg
NDE4NzM0NiwgcmVnaXN0ZXJlZCBvZmZpY2UgQ2h1cmNoaWxsIEhvdXNlLCBD
YW1icmlkZ2UgQnVzaW5lc3MgUGFyaywgQ293bGV5IFJvYWQsIENhbWJyaWRn
ZSwgQ0I0IDBXWiwgVW5pdGVkIEtpbmdkb20KTW9yZSBpbmZvcm1hdGlvbiBj
YW4gYmUgZm91bmQgYXQgd3d3LmNzci5jb20uIEtlZXAgdXAgdG8gZGF0ZSB3
aXRoIENTUiBvbiBvdXIgdGVjaG5pY2FsIGJsb2csIHd3dy5jc3IuY29tL2Js
b2csIENTUiBwZW9wbGUgYmxvZywgd3d3LmNzci5jb20vcGVvcGxlLCBZb3VU
dWJlLCB3d3cueW91dHViZS5jb20vdXNlci9DU1JwbGMsIEZhY2Vib29rLCB3
d3cuZmFjZWJvb2suY29tL3BhZ2VzL0NTUi8xOTEwMzg0MzQyNTM1MzQsIG9y
IGZvbGxvdyB1cyBvbiBUd2l0dGVyIGF0IHd3dy50d2l0dGVyLmNvbS9DU1Jf
cGxjLgpOZXcgZm9yIDIwMTQsIHlvdSBjYW4gbm93IGFjY2VzcyB0aGUgd2lk
ZSByYW5nZSBvZiBwcm9kdWN0cyBwb3dlcmVkIGJ5IGFwdFggYXQgd3d3LmFw
dHguY29tLgo=

Re: Bluetooth Low Energy service crash report - when trying read a HID feature report

[David Herrmann]

Hi

On Mon, Jul 28, 2014 at 12:21 PM, Luiz Augusto von Dentz
<luiz.dentz@gmail.com> wrote:
> Hi David, Murat,
>
> On Mon, Jul 28, 2014 at 11:53 AM, David Herrmann <dh.herrmann@gmail.com> wrote:
>> Hi
>>
>>>> The kernel bails out if size==0, so this never happens. The bt_uhid_*
>>>> helpers are fine, however, hog.c forward_report() is totally broken.
>>>> You use:
>>>>
>>>> bt_uhid_register(hogdev->uhid, UHID_OUTPUT, forward_report, hogdev);
>>>> bt_uhid_register(hogdev->uhid, UHID_FEATURE, forward_report, hogdev);
>>>>
>>>> Therefore, you register *THE SAME* handler for UHID_OUTPUT *AND*
>>>> UHID_FEATURE. However, in forward_report() you access ev->u.output,
>>>> but this is only valid for UHID_OUTPUT. If you get a UHID_FEATURE
>>>> report you must never access anything but ev->u.feature!
>>>
>>> Does the ev->u.features structure matches HID protocol, can I send as
>>> it is or do I need to reformat it?
>>
>> The uhid.h header includes these definitions:
>>
>> struct uhid_feature_req {
>>         __u32 id;
>>         __u8 rnum;
>>         __u8 rtype;
>> } __attribute__((__packed__));
>>
>> struct uhid_feature_answer_req {
>>         __u32 id;
>>         __u16 err;
>>         __u16 size;
>>         __u8 data[UHID_DATA_MAX];
>> } __attribute__((__packed__));
>
> That I got it, what I was asking was if that is the exact same format
> used in HID so that I could sent as it is to the remote device. Im
> afraid the answer is no because id and some other fields seems to be
> just for context tracking as you mention bellow.

Sorry, I wasn't really clear. uhid_feature_req contains 3 fields:

"id" contains a random ID from the kernel. This has no meaning besides
tracking feature_req and feature_answer_req. That is, once your device
answers to the feature request, you must copy the ID into the
uhid_feature_answer_req and send it to the kernel. Note that UHID ever
only has one uhid_feature_req is parallel. Therefore, you can safe the
"id" field in some global context and use it for the next
uhid_feature_answer_req you send. If the kernel cancelled a request
(timeout, interrupted, ...), it will ignore any answer with that ID in
the future.

"rnum": This is the report-number of the feature request.

"rtype": This is the report-type of the feature request. It can be
INPUT, OUTPUT or FEATURE. This is really misleading as you might
expect this is always FEATURE. That's not true though. The
UHID_FEATURE request really should have been called UHID_GET_REPORT.

What you should do once you receive a UHID_FEATURE event from the
kernel, is send a GET_REPORT request to the device. Setting the
report-number to "rnum" and the report-type to "rtype". Once the
device answers to the GET_REPORT, write a "uhid_feature_answer_req" to
the kernel by copying the "id" into it and the answer from the device.
"err" should be set to 0. If something failed, set "err" to a
error-number and leave the other fields untouched (besides "id"). The
answer from the device should be copied untouched into "data" and
"size" set to the length.

The GET_REPORT logic is described in the HIDP specs, so I guess the
HoG specs contain it, too. Note that the spec only allows a _single_
GET_REPORT requests at a time. Therefore, if you sent one out, you
must wait for the answer before sending a new one. Luckily, the kernel
enforces this, so it only sends a new request in case the old one
timed out (5s I think, or 1s?). You can safely do the same in HoG.

>>>> Furthermore, if you receive UHID_FEATURE, the kernel blocks until you
>>>> send the answer as UHID_FEATURE_ANSWER.
>>>
>>> So if I got this right in addition to send the request we should
>>> process the response as UHID_FEATURE_ANSWER otherwise it will block
>>> other events?
>>
>> Kernel HID drivers can use a kernel-internal function to query an
>> HID-feature. This call is blocking and waits for the answer from the
>> device. uhid copied that design to avoid rewriting all drivers.
>> Therefore, IFF you get an UHID_FEATURE event, you have to send the
>> feature request to the device, somewhere store the context, and once
>> the device answers you have to find that context again and write the
>> answer via UHID_FEATURE_ANSWER to the kernel. The "id" field in
>> uhid_feature_req and uhid_feature_answer_req must match and are used
>> for context-tracking.
>>
>> Note that this is only used for HID drivers that require synchronous
>> feature queries. All other drivers use UHID_OUTPUT for all outoing
>> reports. The "rtype" field specifies whether it's an INPUT, OUTPUT or
>> FEATURE report that has to be written. It it thus totally ok to ignore
>> UHID_FEATURE as only few drivers use it.
>
> @Murat, I guess your input is needed here, why are you using
> UHID_FEATURE instead of UHID_OUTPUT? Can we drop UHID_FEATURE or your
> driver really requires it?

I really recommend reading Documentation/hid/hid-transport.txt in the
kernel sources. It's a pretty new document (linux-3.14 I think), but
it describes the design of generic HID transport drivers in detail.
The kernel-internal APIs have been adjusted accordingly, UHID still
follows the old style. I'm currently reworking the API. I will put
linux-bluetooth on CC once ready.
It should be a lot easier to write HoG when you understand these
internals, and hid-transport.txt was written for exactly that purpose.
Please provide feedback to linux-input@vger.kernel.org in case
something is unclear. If you put me on CC, I promise to answer any
questions.

Thanks
David