Hi linux-bluetooth:
I'm seeing the following issue with BlueZ 5.43 and Linux 4.4.30.
When a previously bonded HoG remote control reconnects to BlueZ 5.43
host, BlueZ goes ahead and re-discovers the primary services of the
bonded remote again and again on every reconnect.
Why is this necessary? Shouldn't this information be cached on the
initial pairing/bonding, and a reconnect can get this information from
the relevant persistent file, rather than wasting BLE airtime and
delaying the reconnect?
Here is the log:
15,148349,14484016000,-;btmon: < HCI Command: LE Set Scan Enable
(0x08|0x000c) plen 2 [hci0] 16:45:13.144717
15,148350,14484016000,-;btmon: Scanning: Disabled (0x00)
15,148351,14484016000,-;btmon: Filter duplicates: Disabled (0x00)
15,148352,14484024000,-;btmon: > HCI Event: Command Complete (0x0e)
plen 4 [hci0] 16:45:13.151431
15,148353,14484024000,-;btmon: LE Set Scan Enable (0x08|0x000c) ncmd 1
15,148354,14484024000,-;btmon: Status: Success (0x00)
15,148355,14484024000,-;btmon: < HCI Command: LE Create Connec..
(0x08|0x000d) plen 25 [hci0] 16:45:13.151696
15,148356,14484024000,-;btmon: Scan interval: 60.000 msec (0x0060)
15,148357,14484026000,-;btmon: Scan window: 60.000 msec (0x0060)
15,148358,14484026000,-;btmon: Filter policy: White list is
not used (0x00)
15,148359,14484026000,-;btmon: Peer address type: Public (0x00)
15,148360,14484026000,-;btmon: Peer address: D4:F5:13:xx:xx:xx
(OUI D4-F5-13)
15,148361,14484026000,-;btmon: Own address type: Public (0x00)
15,148362,14484026000,-;btmon: Min connection interval: 10.00
msec (0x0008)
15,148363,14484026000,-;btmon: Max connection interval: 10.00
msec (0x0008)
15,148364,14484026000,-;btmon: Connection latency: 0x0032
15,148365,14484026000,-;btmon: Supervision timeout: 5000 msec (0x01f4)
15,148366,14484026000,-;btmon: Min connection length: 0.000
msec (0x0000)
15,148367,14484026000,-;btmon: Max connection length: 0.000
msec (0x0000)
15,148368,14484035000,-;btmon: > HCI Event: Command Status (0x0f) plen
4 [hci0] 16:45:13.163738
15,148369,14484036000,-;btmon: LE Create Connection (0x08|0x000d) ncmd 1
15,148370,14484036000,-;btmon: Status: Success (0x00)
15,148371,14484042000,-;bluez: bluetoothd[1985]:
src/adapter.c:connected_callback() hci0 device D4:F5:13:xx:xx:xx
connected eir_len 0
15,148372,14484042000,-;bluez: bluetoothd[1985]:
src/adapter.c:connected_callback() device 0x56c520 paired 1 bonded 1
bonding 0
15,148373,14484048000,-;btmon: > HCI Event: LE Meta Event (0x3e) plen
19 [hci0] 16:45:13.166525
15,148374,14484048000,-;btmon: LE Connection Complete (0x01)
15,148375,14484048000,-;btmon: Status: Success (0x00)
15,148376,14484048000,-;btmon: Handle: 128
15,148377,14484048000,-;btmon: Role: Master (0x00)
15,148378,14484048000,-;btmon: Peer address type: Public (0x00)
15,148379,14484048000,-;btmon: Peer address: D4:F5:13:xx:xx:xx
(OUI D4-F5-13)
15,148380,14484048000,-;btmon: Connection interval: 10.00 msec (0x0008)
15,148381,14484048000,-;btmon: Connection latency: 62.50 msec (0x0032)
15,148382,14484048000,-;btmon: Supervision timeout: 5000 msec (0x01f4)
15,148383,14484048000,-;btmon: Master clock accuracy: 0x01
15,148384,14484054000,-;btmon: < HCI Command: LE Read Remote Us..
(0x08|0x0016) plen 2 [hci0] 16:45:13.167102
15,148385,14484057000,-;btmon: Handle: 128
15,148386,14484057000,-;btmon: @ Device Connected: D4:F5:13:xx:xx:xx
(1) flags 0x0000
15,148387,14484060000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 6 [hci0] 16:45:13.186288
15,148388,14484060000,-;btmon: SMP: Security Request (0x0b) len 1
15,148389,14484060000,-;btmon: Authentication requirement:
Bonding, MITM, Legacy, No Keypresses (0x05)
15,148390,14484060000,-;btmon: > HCI Event: Command Status (0x0f) plen
4 [hci0] 16:45:13.187449
15,148391,14484060000,-;btmon: LE Read Remote Used Features
(0x08|0x0016) ncmd 1
15,148392,14484060000,-;btmon: Status: Success (0x00)
15,148393,14484083000,-;btmon: > HCI Event: LE Meta Event (0x3e) plen
12 [hci0] 16:45:13.204567
15,148394,14484083000,-;btmon: LE Read Remote Used Features (0x04)
15,148395,14484083000,-;btmon: Status: Success (0x00)
15,148396,14484083000,-;btmon: Handle: 128
15,148397,14484083000,-;btmon: Features: 0x01 0x00 0x00 0x00
0x00 0x00 0x00 0x00
15,148398,14484083000,-;btmon: LE Encryption
15,148399,14484084000,-;bluez: bluetoothd[1985]:
src/gatt-database.c:connect_cb() New incoming LE ATT connection
15,148400,14484084000,-;bluez: bluetoothd[1985]:
src/device.c:device_attach_att() Elevating security level since LTK is
available
15,148401,14484090000,-;btmon: < HCI Command: LE Start Encrypt..
(0x08|0x0019) plen 28 [hci0] 16:45:13.204768
15,148402,14484092000,-;btmon: Handle: 128
15,148403,14484092000,-;btmon: Random number: 0x2f1ece959be98720
15,148404,14484092000,-;btmon: Encrypted diversifier: 0xf64c
15,148405,14484092000,-;btmon: Long term key:
81f83ba06c91dd2e8a19cbe65fd5123a
15,148406,14484095000,-;btmon: > HCI Event: Command Status (0x0f) plen
4 [hci0] 16:45:13.219246
15,148407,14484097000,-;btmon: LE Start Encryption (0x08|0x0019) ncmd 1
15,148408,14484098000,-;btmon: Status: Success (0x00)
15,148409,14484101000,-;bluez: bluetoothd[1985]:
attrib/gattrib.c:g_attrib_ref() 0x51aab8: g_attrib_ref=1
15,148410,14484101000,-;bluez: bluetoothd[1985]:
profiles/gap/gas.c:gap_accept() GAP profile accept (D4:F5:13:xx:xx:xx)
15,148411,14484103000,-;bluez: bluetoothd[1985]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a02-0000-1000-8000-00805f9b34fb
15,148412,14484104000,-;bluez: bluetoothd[1985]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a03-0000-1000-8000-00805f9b34fb
15,148413,14484112000,-;bluez: bluetoothd[1985]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a04-0000-1000-8000-00805f9b34fb
15,148414,14484119000,-;bluez: bluetoothd[1985]:
src/service.c:change_state() 0x56ae98: device D4:F5:13:xx:xx:xx
profile gap-profile state changed: disconnected -> connected (0)
15,148415,14484121000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:deviceinfo_accept() deviceinfo
profile accept (D4:F5:13:xx:xx:xx)
15,148416,14484121000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a23-0000-1000-8000-00805f9b34fb
15,148417,14484123000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a24-0000-1000-8000-00805f9b34fb
15,148418,14484124000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a25-0000-1000-8000-00805f9b34fb
15,148419,14484125000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a26-0000-1000-8000-00805f9b34fb
15,148420,14484127000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a27-0000-1000-8000-00805f9b34fb
15,148421,14484127000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a28-0000-1000-8000-00805f9b34fb
15,148422,14484132000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a29-0000-1000-8000-00805f9b34fb
15,148423,14484133000,-;bluez: bluetoothd[1985]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a2a-0000-1000-8000-00805f9b34fb
15,148424,14484136000,-;bluez: bluetoothd[1985]:
src/service.c:change_state() 0x512ff0: device D4:F5:13:xx:xx:xx
profile deviceinfo state changed: disconnected -> connected (0)
15,148425,14484139000,-;bluez: bluetoothd[1985]:
profiles/battery/battery.c:batt_accept() BATT connected
15,148426,14484139000,-;bluez: bluetoothd[1985]:
src/service.c:change_state() 0x517cf0: device D4:F5:13:xx:xx:xx
profile Battery state changed: disconnected -> connected (0)
15,148427,14484141000,-;bluez: bluetoothd[1985]:
plugins/policy.c:service_cb() Added Battery reconnect 0
15,148428,14484142000,-;bluez: bluetoothd[1985]:
profiles/scanparam/scan.c:scan_param_accept() Scan Parameters Client
Driver profile accept (D4:F5:13:xx:xx:xx)
15,148429,14484147000,-;bluez: bluetoothd[1985]:
profiles/scanparam/scan.c:handle_iwin() Scan Interval Window handle:
0x002b
15,148430,14484150000,-;bluez: bluetoothd[1985]:
profiles/scanparam/scan.c:handle_refresh() Scan Refresh handle: 0x002d
15,148431,14484151000,-;bluez: bluetoothd[1985]:
src/service.c:change_state() 0x563e48: device D4:F5:13:xx:xx:xx
profile Scan Parameters Client Driver state changed: disconnected ->
connected (0)
15,148434,14484159000,-;bluez: bluetoothd[1985]:
src/service.c:change_state() 0x517cd0: device D4:F5:13:xx:xx:xx
profile input-hog state changed: disconnected -> connected (0)
15,148435,14484159000,-;bluez: bluetoothd[1985]:
plugins/policy.c:service_cb() Added input-hog reconnect 0
15,148436,14484162000,-;bluez: bluetoothd[1985]:
profiles/oad/oad.c:oad_accept() OAD connected
15,148437,14484164000,-;bluez: bluetoothd[1985]:
src/service.c:change_state() 0x56aa90: device D4:F5:13:xx:xx:xx
profile OAD state changed: disconnected -> connected (0)
15,148438,14484167000,-;bluez: bluetoothd[1985]:
plugins/policy.c:service_cb() Added OAD reconnect 0
15,148439,14484168000,-;bluez: bluetoothd[1985]:
profiles/oad/oad.c:oad_is_time_for_upgrade_check() OAD not time for
upgrade check yet (27717 seconds left)
15,148440,14484172000,-;bluez: bluetoothd[1985]:
src/gatt-client.c:btd_gatt_client_connected() Device connected.
15,148444,14484647000,-;btmon: > HCI Event: Encryption Change (0x08)
plen 4 [hci0] 16:45:13.772757
15,148445,14484648000,-;btmon: Status: Success (0x00)
15,148446,14484650000,-;btmon: Handle: 128
15,148447,14484650000,-;btmon: Encryption: Enabled with AES-CCM (0x01)
15,148448,14484650000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:13.773623
15,148449,14484650000,-;btmon: ATT: Write Command (0x52) len 6
15,148450,14484650000,-;btmon: Handle: 0x002b
15,148451,14484650000,-;btmon: Data: 60003000
15,148452,14484650000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 7 [hci0] 16:45:13.776191
15,148453,14484650000,-;btmon: ATT: Exchange MTU Request (0x02) len 2
15,148454,14484650000,-;btmon: Client RX MTU: 517
15,148455,14484653000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:13.781800
15,148456,14484654000,-;btmon: Num handles: 1
15,148457,14484654000,-;btmon: Handle: 128
15,148458,14484654000,-;btmon: Count: 1
15,148459,14484656000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 8 [hci0] 16:45:13.783776
15,148460,14484656000,-;btmon: ATT: Handle Value Notification (0x1b) len 3
15,148461,14484656000,-;btmon: Handle: 0x002e
15,148462,14484656000,-;btmon: Data: 00
15,148463,14484658000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:13.785586
15,148464,14484658000,-;btmon: Num handles: 1
15,148465,14484658000,-;btmon: Handle: 128
15,148466,14484658000,-;btmon: Count: 1
15,148467,14484676000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
15,148468,14484676000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 7 [hci0] 16:45:13.803216
15,148469,14484676000,-;btmon: ATT: Exchange MTU Response (0x03) len 2
15,148470,14484676000,-;btmon: Server RX MTU: 23
15,148471,14484680000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 7 [hci0] 16:45:13.805360
15,148472,14484680000,-;btmon: ATT: Read Request (0x0a) len 2
15,148473,14484680000,-;btmon: Handle: 0x0003
15,148476,14485197000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:14.323660
15,148477,14485197000,-;btmon: Num handles: 1
15,148478,14485197000,-;btmon: Handle: 128
15,148479,14485197000,-;btmon: Count: 1
15,148480,14485215000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 12 [hci0] 16:45:14.343324
15,148481,14485215000,-;btmon: ATT: Read Response (0x0b) len 7
15,148482,14485215000,-;btmon: Value: xxxxxxxx
15,148483,14485216000,-;bluez: bluetoothd[1985]:
profiles/gap/gas.c:read_device_name_cb() GAP Device Name: xxxxxxxx
15,148484,14485218000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 7 [hci0] 16:45:14.345190
15,148485,14485218000,-;btmon: ATT: Read Request (0x0a) len 2
15,148486,14485218000,-;btmon: Handle: 0x0005
15,148487,14485280000,-;btmon: > HCI Event: Vendor (0xff) plen 5
[hci0] 16:45:14.408751
15,148488,14485280000,-;btmon: 05 80 00 09 00
.....
15,148497,14485736000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:14.864603
15,148498,14485736000,-;btmon: Num handles: 1
15,148499,14485736000,-;btmon: Handle: 128
15,148500,14485736000,-;btmon: Count: 1
15,148501,14485744000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 7 [hci0] 16:45:14.871746
15,148502,14485744000,-;btmon: ATT: Read Response (0x0b) len 2
15,148503,14485744000,-;btmon: Value: c003
15,148504,14485744000,-;bluez: bluetoothd[1985]:
profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x03c0
15,148505,14485746000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 7 [hci0] 16:45:14.873179
15,148506,14485746000,-;btmon: ATT: Read Request (0x0a) len 214487
15,148507,14485746000,-;btmon: Handle: 0x0022
15,148508,14485754000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:14.881837
15,148509,14485754000,-;btmon: Num handles: 1
15,148510,14485754000,-;btmon: Handle: 128
15,148511,14485754000,-;btmon: Count: 1
15,148512,14485769000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 12 [hci0] 16:45:14.895082
15,148513,14485769000,-;btmon: ATT: Read Response (0x0b) len 7
15,148514,14485771000,-;btmon: Value: 010d0001f01600
15,148515,14485771000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 7 [hci0] 16:45:14.895711
15,148516,14485771000,-;btmon: ATT: Read Request (0x0a) len 2
15,148517,14485772000,-;btmon: Handle: 0x0
15,148518,14485775000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:14.903381
15,148519,14485775000,-;btmon: Num handles: 1
15,148520,14485775000,-;btmon: Handle: 128
15,148521,14485775000,-;btmon: Count: 1
15,148522,14485786000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 6 [hci0] 16:45:14.913585
15,148523,14485786000,-;btmon: ATT: Read Response (0x0b) len 1
15,148524,14485788000,-;bluez: bluetoothd[1985]:
profiles/battery/battery.c:level_read_char_cb() BATT level=100
15,148525,14485788000,-;btmon: Value: 64
15,148526,14485790000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 9 [hci0] 16:45:14.918396
15,148527,14485790000,-;btmon: ATT: Write Request (0x12) len 4
15,148528,14485790000,-;btmon: Handle: 0x002e
15,148529,14485790000,-;btmon: Data: 0100
15,148531,14486306000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.434853
15,148532,14486306000,-;btmon: Num handles: 1
15,148533,14486306000,-;btmon: Handle: 128
15,148534,14486306000,-;btmon: Count: 1
15,148535,14486316000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 5 [hci0] 16:45:15.443551
15,148536,14486316000,-;btmon: ATT: Write Response (0x13) len 0
15,148537,14486317000,-;bluez: bluetoothd[1985]:
profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
notification enabled
15,148538,14486317000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.444853
15,148539,14486317000,-;btmon: ATT: Read By Type Request (0x08) len 6
15,148540,14486317000,-;btmon: Handle range: 0x002f-0x0037
15,148541,14486318000,-;btmon: Attribute type: Characteristic (0x2803)
15,148542,14486326000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.454609
15,148543,14486326000,-;btmon: Num handles: 1
15,148544,14486326000,-;btmon: Handle: 128
15,148545,14486326000,-;btmon: Count: 1
15,148546,14486356000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 27 [hci0] 16:45:15.484547
15,148547,14486356000,-;btmon: ATT: Read By Type Response (0x09) len 22
15,148548,14486356000,-;btmon: Attribute data length: 7
15,148549,14486356000,-;btmon: Attribute data list: 3 entries
15,148550,14486357000,-;btmon: Handle: 0x0030
15,148551,14486357000,-;btmon: Value: 1e3100f1ff
15,148552,14486357000,-;btmon: Handle: 0x0033
15,148553,14486357000,-;btmon: Value: 0a3400f2ff
15,148554,14486357000,-;btmon: Handle: 0x0035
15,148555,14486357000,-;btmon: Value: 123600f4ff
BlueZ request to re-discover peripheral's Primary Service starts below:
15,148556,14486357000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.485545
15,148557,14486357000,-;btmon: ATT: Read By Group Type Request
(0x10) len 6
15,148558,14486358000,-;btmon: Handle range: 0x0001-0xffff
15,148559,14486358000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,148560,14486364000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.491805
15,148561,14486364000,-;btmon: Num handles: 1
15,148562,14486364000,-;btmon: Handle: 128
15,148563,14486364000,-;btmon: Count: 1
15,148564,14486384000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 24 [hci0] 16:45:15.511935
15,148565,14486384000,-;btmon: ATT: Read By Group Type Response
(0x11) len 19
15,148566,14486384000,-;btmon: Attribute data length: 6
15,148567,14486384000,-;btmon: Attribute group list: 3 entries
15,148568,14486384000,-;btmon: Handle range: 0x0001-0x000b
15,148569,14486384000,-;btmon: UUID: Generic Access Profile (0x1800)
15,148570,14486385000,-;btmon: Handle range: 0x000c-0x000f
15,148571,14486385000,-;btmon: UUID: Generic Attribute Profile (0x1801)
15,148572,14486385000,-;btmon: Handle range: 0x0010-0x0022
15,148573,14486386000,-;btmon: UUID: Device Information (0x180a)
15,148574,14486386000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.512563
15,148575,14486386000,-;btmon: ATT: Read By Type Request (0x08) len 6
15,148576,14486386000,-;btmon: Handle range: 0x0036-0x0037
15,148577,14486386000,-;btmon: Attribute type: Characteristic (0x2803)
15,148578,14486395000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.521844
15,148579,14486395000,-;btmon: Num handles: 1
15,148580,14486395000,-;btmon: Handle: 128
15,148581,14486400000,-;btmon: Count: 1
15,148582,14486404000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 9 [hci0] 16:45:15.532197
15,148583,14486404000,-;btmon: ATT: Error Response (0x01) len 4
15,148584,14486404000,-;btmon: Read By Type Request (0x08)
15,148585,14486404000,-;btmon: Handle: 0x0036
15,148586,14486404000,-;btmon: Error: Attribute Not Found (0x0a)
15,148587,14486405000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.533289
15,148588,14486405000,-;btmon: ATT: Read By Group Type Request
(0x10) len 6
15,148589,14486405000,-;btmon: Handle range: 0x0023-0xffff
15,148590,14486405000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,148591,14486414000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.541821
15,148592,14486414000,-;btmon: Num handles: 1
15,148593,14486414000,-;btmon: Handle: 128
15,148594,14486414000,-;btmon: Count: 1
15,148595,14486448000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 24 [hci0] 16:45:15.574739
15,148596,14486449000,-;btmon: ATT: Read By Group Type Response
(0x11) len 19
15,148597,14486449000,-;btmon: Attribute data length: 6
15,148598,14486450000,-;btmon: Attribute group list: 3 entries
15,148599,14486450000,-;btmon: Handle range: 0x0023-0x0028
15,148600,14486450000,-;btmon: UUID: Battery Service (0x180f)
15,148601,14486450000,-;btmon: Handle range: 0x0029-0x002e
15,148602,14486450000,-;btmon: UUID: Scan Parameters (0x1813)
15,148603,14486450000,-;btmon: Handle range: 0x002f-0x0037
15,148604,14486450000,-;btmon: UUID: Unknown (0xfff0)
15,148605,14486450000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 9 [hci0] 16:45:15.575704
15,148606,14486450000,-;btmon: ATT: Find Information Request (0x04) len 4
15,148607,14486450000,-;btmon: Handle range: 0x0036-0x0037
15,148608,14486454000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.581832
15,148609,14486454000,-;btmon: Num handles: 1
15,148610,14486454000,-;btmon: Handle: 128
15,148611,14486454000,-;btmon: Count: 1
15,148614,14486476000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 14 [hci0] 16:45:15.603418
15,148615,14486476000,-;btmon: ATT: Find Information Response (0x05) len 9
15,148616,14486476000,-;btmon: Format: UUID-16 (0x01)
15,148617,14486476000,-;btmon: Handle: 0x0036
15,148618,14486476000,-;btmon: UUID: Unknown (0xfff4)
15,148619,14486477000,-;btmon: Handle: 0x0037
15,148620,14486477000,-;btmon: UUID: Client Characteristic
Configuration (0x2902)
15,148621,14486477000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 10 [hci0] 16:45:15.604557
15,148622,14486477000,-;btmon: ATT: Write Request (0x12) len 5
15,148623,14486477000,-;btmon: Handle: 0x0034
15,148624,14486477000,-;btmon: Data: 030000
15,148625,14486485000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.613570
15,148626,14486485000,-;btmon: Num handles: 1
15,148627,14486485000,-;btmon: Handle: 128
15,148628,14486485000,-;btmon: Count: 1
15,148629,14486496000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 5 [hci0] 16:45:15.623625
15,148630,14486496000,-;btmon: ATT: Write Response (0x13) len 0
15,148631,14486496000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.624699
15,148632,14486496000,-;btmon: ATT: Read By Group Type Request
(0x10) len 6
15,148633,14486496000,-;btmon: Handle range: 0x0038-0xffff
15,148634,14486496000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,148635,14486509000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.637188
15,148636,14486509000,-;btmon: Num handles: 1
15,148637,14486509000,-;btmon: Handle: 128
15,148638,14486509000,-;btmon: Count: 1
15,148639,14486525000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 12 [hci0] 16:45:15.652267
15,148640,14486525000,-;btmon: ATT: Read By Group Type Response
(0x11) len 7
15,148641,14486525000,-;btmon: Attribute data length: 6
15,148642,14486525000,-;btmon: Attribute group list: 1 entry
15,148643,14486525000,-;btmon: Handle range: 0x0038-0x005c
15,148644,14486525000,-;btmon: UUID: Human Interface Device (0x1812)
15,148645,14486526000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 9 [hci0] 16:45:15.654189
15,148646,14486526000,-;btmon: ATT: Write Request (0x12) len 4
15,148647,14486526000,-;btmon: Handle: 0x0037
15,148648,14486526000,-;btmon: Data: 0100
15,148650,14486543000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.671923
15,148651,14486543000,-;btmon: Num handles: 1
15,148652,14486543000,-;btmon: Handle: 128
15,148653,14486544000,-;btmon: Count: 1
15,148654,14486574000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 5 [hci0] 16:45:15.702603
15,148655,14486574000,-;btmon: ATT: Write Response (0x13) len 0
15,148656,14486575000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.703208
15,148657,14486575000,-;btmon: ATT: Read By Group Type Request
(0x10) len 6
15,148658,14486575000,-;btmon: Handle range: 0x005d-0xffff
15,148659,14486575000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,148660,14486586000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:15.714715
15,148661,14486586000,-;btmon: Num handles: 1
15,148662,14486586000,-;btmon: Handle: 128
15,148663,14486586000,-;btmon: Count: 1
15,148664,14486617000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 26 [hci0] 16:45:15.744781
15,148665,14486617000,-;btmon: ATT: Read By Group Type Response
(0x11) len 21
15,148666,14486617000,-;btmon: Attribute data length: 20
15,148667,14486617000,-;btmon: Attribute group list: 1 entry
15,148668,14486617000,-;btmon: Handle range: 0x005d-0x0070
15,148669,14486617000,-;btmon: UUID: Vendor specific
(f000fef0-0451-4000-b000-000000000000)
15,148670,14486618000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 11 [hci0] 16:45:15.746142
15,148671,14486619000,-;btmon: ATT: Read By Group Type Request
(0x10) len 6
15,148672,14486619000,-;btmon: Handle range: 0x0071-0xffff
15,148673,14486620000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,148675,14487139000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:16.267193
15,148676,14487139000,-;btmon: Num handles: 1
15,148677,14487139000,-;btmon: Handle: 128
15,148678,14487139000,-;btmon: Count: 1
15,148679,14487156000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 26 [hci0] 16:45:16.284511
15,148680,14487156000,-;btmon: ATT: Read By Group Type Response
(0x11) len 21
15,148681,14487156000,-;btmon: Attribute data length: 20
15,148682,14487156000,-;btmon: Attribute group list: 1 entry
15,148683,14487157000,-;btmon: Handle range: 0x0071-0xffff
15,148684,14487157000,-;btmon: UUID: Vendor specific
(f000ffc0-0451-4000-b000-000000000000)
15,148685,14487157000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() Primary services found: 9
15,148686,14487157000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x0001, end: 0x000b, uuid:
00001800-0000-1000-8000-00805f9b34fb
15,148687,14487157000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x000c, end: 0x000f, uuid:
00001801-0000-1000-8000-00805f9b34fb
15,148688,14487158000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x0010, end: 0x0022, uuid:
0000180a-0000-1000-8000-00805f9b34fb
15,148689,14487158000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x0023, end: 0x0028, uuid:
0000180f-0000-1000-8000-00805f9b34fb
15,148690,14487160000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x0029, end: 0x002e, uuid:
00001813-0000-1000-8000-00805f9b34fb
15,148691,14487160000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x002f, end: 0x0037, uuid:
0000fff0-0000-1000-8000-00805f9b34fb
15,148692,14487160000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x0038, end: 0x005c, uuid:
00001812-0000-1000-8000-00805f9b34fb
15,148693,14487161000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x005d, end: 0x0070, uuid:
f000fef0-0451-4000-b000-000000000000
15,148694,14487163000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() start: 0x0071, end: 0xffff, uuid:
f000ffc0-0451-4000-b000-000000000000
15,148695,14487166000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_client_ready_cb() status: success, error: 0
15,148696,14487169000,-;bluez: bluetoothd[1985]:
src/gatt-client.c:btd_gatt_client_ready() GATT client ready
15,148697,14487169000,-;bluez: bluetoothd[1985]:
src/gatt-client.c:create_services() Exporting objects for GATT
services: D4:F5:13:xx:xx:xx
15,148698,14487169000,-;bluez: bluetoothd[1985]:
src/device.c:device_svc_resolved()
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx err 0
15,148700,14487208000,-;btmon: < ACL Data TX: Handle 128 flags 0x00
dlen 9 [hci0] 16:45:16.336263
15,148701,14487208000,-;btmon: ATT: Write Request (0x12) len 4
15,148702,14487208000,-;btmon: Handle: 0x000f
15,148703,14487208000,-;btmon: Data: 0200
15,148713,14487675000,-;btmon: > HCI Event: Number of Completed
Packets (0x13) plen 5 [hci0] 16:45:16.803794
15,148714,14487675000,-;btmon: Num handles: 1
15,148715,14487676000,-;btmon: Handle: 128
15,148716,14487676000,-;btmon: Count: 1
15,148717,14487705000,-;btmon: > ACL Data RX: Handle 128 flags 0x02
dlen 5 [hci0] 16:45:16.833390
15,148718,14487705000,-;btmon: ATT: Write Response (0x13) len 0
15,148719,14487706000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() Registered handler for "Service Changed": 2
In the above log, I see that MTU exchange takes place:
15,148467,14484676000,-;bluez: bluetoothd[1985]:
src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
Looking at the relevant code in src/shared/gatt-client.c, function
exchange_mtu_cb():
util_debug(client->debug_callback, client->debug_data,
"MTU exchange complete, with MTU: %u",
bt_att_get_mtu(client->att));
discover:
client->discovery_req = bt_gatt_discover_all_primary_services(
client->att, NULL,
discover_primary_cb,
discovery_op_ref(op),
discovery_op_unref);
The call to bt_gatt_discover_all_primary_services() is unconditional,
whether the device was previously bonded or not.
-- Petri
Hi Petri,
On Fri, Nov 11, 2016 at 4:42 AM, Petri Gynther <[email protected]> wrote:
> Hi Luiz,
>
> On Thu, Nov 10, 2016 at 6:17 AM, Luiz Augusto von Dentz
> <[email protected]> wrote:
>> Hi Petri,
>>
>> On Wed, Nov 9, 2016 at 9:39 PM, Petri Gynther <[email protected]> wrote:
>>> Hi linux-bluetooth:
>>>
>>> I'm seeing the following issue with BlueZ 5.43 and Linux 4.4.30.
>>>
>>> When a previously bonded HoG remote control reconnects to BlueZ 5.43
>>> host, BlueZ goes ahead and re-discovers the primary services of the
>>> bonded remote again and again on every reconnect.
>>>
>>> Why is this necessary? Shouldn't this information be cached on the
>>> initial pairing/bonding, and a reconnect can get this information from
>>> the relevant persistent file, rather than wasting BLE airtime and
>>> delaying the reconnect?
>>>
>>
>> IF, and only if, the cache is restored properly then yes it will work
>> as you said, but bt_hog is not yet using the gatt_db so it might
>> rediscover the handles anyway, this happens only once though.
>>
>>>
>>>
>>> In the above log, I see that MTU exchange takes place:
>>> 15,148467,14484676000,-;bluez: bluetoothd[1985]:
>>> src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
>>>
>>> Looking at the relevant code in src/shared/gatt-client.c, function
>>> exchange_mtu_cb():
>>>
>>> util_debug(client->debug_callback, client->debug_data,
>>> "MTU exchange complete, with MTU: %u",
>>> bt_att_get_mtu(client->att));
>>>
>>> discover:
>>> client->discovery_req = bt_gatt_discover_all_primary_services(
>>> client->att, NULL,
>>> discover_primary_cb,
>>> discovery_op_ref(op),
>>> discovery_op_unref);
>>>
>>>
>>> The call to bt_gatt_discover_all_primary_services() is unconditional,
>>> whether the device was previously bonded or not.
>>
>> This does range validation in case service changed is not properly
>> implemented this will attempt to figure out if there are any changes
>> in the database, but note that it will stop in here:
>>
>> attr = gatt_db_insert_service(client->db, start, &uuid, true,
>> end - start + 1);
>> if (!attr) {
>>
>> So if the database already contain all the services it will no do more
>> than one Read By Group Type.
Looking into btmon details after the line marked ====:
> 15,18491,832722000,-;bluez: bluetoothd[2346]:
> profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
> notification enabled
>
> We can see that BlueZ issues a bunch of ATT: Read By Group Type
> Requests to re-discover all primary services (0x2800):
This is what I said, we will issue Read By Group Type to validate the
cached data since service changed is not mandatory and way too many
devices don't implement it correctly.
> 15,18491,832722000,-;bluez: bluetoothd[2346]:
> profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
> notification enabled
> 15,18492,832723000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:51.730522
> 15,18493,832725000,-;btmon: ATT: Read By Type Request (0x08) len 6
> 15,18494,832725000,-;btmon: Handle range: 0x002f-0x0037
> 15,18495,832725000,-;btmon: Attribute type: Characteristic (0x2803)
> 15,18496,832725000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:51.731128
> 15,18497,832726000,-;btmon: Num handles: 1
> 15,18498,832726000,-;btmon: Handle: 128
> 15,18499,832726000,-;btmon: Count: 1
> 15,18500,832733000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:51.739362
> 15,18501,832733000,-;btmon: Num handles: 1
> 15,18502,832733000,-;btmon: Handle: 128
> 15,18503,832733000,-;btmon: Count: 1
> 15,18504,832752000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 27 [hci0] 17:26:51.759357
> 15,18505,832753000,-;btmon: ATT: Read By Type Response (0x09) len 22
> 15,18506,832753000,-;btmon: Attribute data length: 7
> 15,18507,832753000,-;btmon: Attribute data list: 3 entries
> 15,18508,832753000,-;btmon: Handle: 0x0030
> 15,18509,832753000,-;btmon: Value: 1e3100f1ff
> 15,18510,832753000,-;btmon: Handle: 0x0033
> 15,18511,832753000,-;btmon: Value: 0a3400f2ff
> 15,18512,832753000,-;btmon: Handle: 0x0035
> 15,18513,832753000,-;btmon: Value: 123600f4ff
> 15,18514,832754000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:51.760043
> 15,18515,832754000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
> 15,18516,832754000,-;btmon: Handle range: 0x0001-0xffff
> 15,18517,832754000,-;btmon: Attribute group type: Primary
> Service (0x2800)
> 15,18518,832762000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:51.769346
> 15,18519,832762000,-;btmon: Num handles: 1
> 15,18520,832762000,-;btmon: Handle: 128
> 15,18521,832762000,-;btmon: Count: 1
> 15,18522,832782000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 24 [hci0] 17:26:51.789303
> 15,18523,832782000,-;btmon: ATT: Read By Group Type Response (0x11) len 19
> 15,18524,832782000,-;btmon: Attribute data length: 6
> 15,18525,832782000,-;btmon: Attribute group list: 3 entries
> 15,18526,832784000,-;btmon: Handle range: 0x0001-0x000b
> 15,18527,832784000,-;btmon: UUID: Generic Access Profile (0x1800)
> 15,18528,832784000,-;btmon: Handle range: 0x000c-0x000f
> 15,18529,832784000,-;btmon: UUID: Generic Attribute Profile (0x1801)
> 15,18530,832784000,-;btmon: Handle range: 0x0010-0x0022
> 15,18531,832784000,-;btmon: UUID: Device Information (0x180a)
> 15,18532,832784000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:51.790028
> 15,18533,832784000,-;btmon: ATT: Read By Type Request (0x08) len 6
> 15,18534,832784000,-;btmon: Handle range: 0x0036-0x0037
> 15,18535,832784000,-;btmon: Attribute type: Characteristic (0x2803)
> 15,18536,832792000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:51.799354
> 15,18537,832792000,-;btmon: Num handles: 1
> 15,18538,832792000,-;btmon: Handle: 128
> 15,18539,832792000,-;btmon: Count: 1
> 15,18540,832809000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 9 [hci0] 17:26:51.808179
> 15,18541,832809000,-;btmon: ATT: Error Response (0x01) len 4
> 15,18542,832809000,-;btmon: Read By Type Request (0x08)
> 15,18543,832809000,-;btmon: Handle: 0x0036
> 15,18544,832809000,-;btmon: Error: Attribute Not Found (0x0a)
> 15,18546,832811000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:51.810774
> 15,18547,832812000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
> 15,18548,832812000,-;btmon: Handle range: 0x0023-0xffff
> 15,18549,832812000,-;btmon: Attribute group type: Primary
> Service (0x2800)
> 15,18553,833321000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:52.328191
> 15,18554,833321000,-;btmon: Num handles: 1
> 15,18555,833321000,-;btmon: Handle: 128
> 15,18556,833321000,-;btmon: Count: 1
> 15,18558,833334000,-;btmon: > HCI Event: Vendor (0xff) plen 5
> [hci0] 17:26:52.339515
> 15,18559,833334000,-;btmon: 05 80 00 09 00
> .....
> 15,18560,833362000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 24 [hci0] 17:26:52.369478
> 15,18561,833363000,-;btmon: ATT: Read By Group Type Response (0x11) len 19
> 15,18562,833363000,-;btmon: Attribute data length: 6
> 15,18563,833363000,-;btmon: Attribute group list: 3 entries
> 15,18564,833364000,-;btmon: Handle range: 0x0023-0x0028
> 15,18565,833364000,-;btmon: UUID: Battery Service (0x180f)
> 15,18566,833364000,-;btmon: Handle range: 0x0029-0x002e
> 15,18567,833364000,-;btmon: UUID: Scan Parameters (0x1813)
> 15,18568,833364000,-;btmon: Handle range: 0x002f-0x0037
> 15,18569,833364000,-;btmon: UUID: Unknown (0xfff0)
> 15,18570,833364000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 9 [hci0] 17:26:52.370138
I have to check but these command bellow seems to be unrelated to the discover.
> 15,18571,833364000,-;btmon: ATT: Find Information Request (0x04) len 4
> 15,18572,833364000,-;btmon: Handle range: 0x0036-0x0037
> 15,18574,833371000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:52.378203
> 15,18575,833371000,-;btmon: Num handles: 1
> 15,18576,833371000,-;btmon: Handle: 128
> 15,18577,833371000,-;btmon: Count: 1
> 15,18578,833391000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 14 [hci0] 17:26:52.398166
> 15,18579,833391000,-;btmon: ATT: Find Information Response (0x05) len 9
> 15,18580,833392000,-;btmon: Format: UUID-16 (0x01)
> 15,18582,833394000,-;btmon: Handle: 0x0036
> 15,18583,833394000,-;btmon: UUID: Unknown (0xfff4)
> 15,18584,833394000,-;btmon: Handle: 0x0037
> 15,18585,833394000,-;btmon: UUID: Client Characteristic
> Configuration (0x2902)
> 15,18586,833394000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 10 [hci0] 17:26:52.400735
> 15,18587,833394000,-;btmon: ATT: Write Request (0x12) len 5
> 15,18588,833394000,-;btmon: Handle: 0x0034
> 15,18589,833394000,-;btmon: Data: 030000
> 15,18591,833912000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:52.919397
> 15,18592,833912000,-;btmon: Num handles: 1
> 15,18593,833912000,-;btmon: Handle: 128
> 15,18594,833912000,-;btmon: Count: 1
> 15,18595,833931000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 5 [hci0] 17:26:52.938157
> 15,18596,833931000,-;btmon: ATT: Write Response (0x13) len 0
> 15,18597,833932000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:52.939032
Were we just continue with the primary discovery.
> 15,18598,833932000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
> 15,18599,833932000,-;btmon: Handle range: 0x0038-0xffff
> 15,18600,833932000,-;btmon: Attribute group type: Primary
> Service (0x2800)
> 15,18601,833944000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:52.951628
> 15,18602,833944000,-;btmon: Num handles: 1
> 15,18603,833944000,-;btmon: Handle: 128
> 15,18604,833944000,-;btmon: Count: 1
> 15,18605,833959000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 12 [hci0] 17:26:52.966479
> 15,18606,833959000,-;btmon: ATT: Read By Group Type Response (0x11) len 7
> 15,18607,833960000,-;btmon: Attribute data length: 6
> 15,18608,833960000,-;btmon: Attribute group list: 1 entry
> 15,18609,833960000,-;btmon: Handle range: 0x0038-0x005c
> 15,18610,833960000,-;btmon: UUID: Human Interface Device (0x1812)
> 15,18611,833960000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 9 [hci0] 17:26:52.967113
> 15,18612,833960000,-;btmon: ATT: Write Request (0x12) len 4
> 15,18613,833960000,-;btmon: Handle: 0x0037
> 15,18614,833960000,-;btmon: Data: 0100
> 15,18615,833971000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:52.976999
> 15,18616,833971000,-;btmon: Num handles: 1
> 15,18617,833972000,-;btmon: Handle: 128
> 15,18618,833972000,-;btmon: Count: 1
> 15,18619,833979000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 5 [hci0] 17:26:52.986355
> 15,18620,833980000,-;btmon: ATT: Write Response (0x13) len 0
> 15,18621,833980000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:52.986894
> 15,18622,833980000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
> 15,18623,833980000,-;btmon: Handle range: 0x005d-0xffff
> 15,18624,833980000,-;btmon: Attribute group type: Primary
> Service (0x2800)
> 15,18625,833990000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:52.996610
> 15,18626,833990000,-;btmon: Num handles: 1
> 15,18627,833991000,-;btmon: Handle: 128
> 15,18628,833991000,-;btmon: Count: 1
> 15,18629,834013000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 26 [hci0] 17:26:53.019401
> 15,18630,834013000,-;btmon: ATT: Read By Group Type Response (0x11) len 21
> 15,18631,834013000,-;btmon: Attribute data length: 20
> 15,18632,834013000,-;btmon: Attribute group list: 1 entry
> 15,18633,834013000,-;btmon: Handle range: 0x005d-0x0070
> 15,18634,834013000,-;btmon: UUID: Vendor specific
> (f000fef0-0451-4000-b000-000000000000)
> 15,18635,834013000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
> 11 [hci0] 17:26:53.020026
> 15,18636,834013000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
> 15,18637,834013000,-;btmon: Handle range: 0x0071-0xffff
> 15,18638,834013000,-;btmon: Attribute group type: Primary
> Service (0x2800)
> 15,18639,834022000,-;btmon: > HCI Event: Number of Completed Packets
> (0x13) plen 5 [hci0] 17:26:53.029922
> 15,18640,834022000,-;btmon: Num handles: 1
> 15,18641,834022000,-;btmon: Handle: 128
> 15,18642,834023000,-;btmon: Count: 1
> 15,18643,834042000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
> 26 [hci0] 17:26:53.049348
> 15,18644,834042000,-;btmon: ATT: Read By Group Type Response (0x11) len 21
> 15,18645,834042000,-;btmon: Attribute data length: 20
> 15,18646,834042000,-;btmon: Attribute group list: 1 entry
> 15,18647,834042000,-;btmon: Handle range: 0x0071-0xffff
> 15,18648,834042000,-;btmon: UUID: Vendor specific
So there is nothing new in the behavior, it does recheck the if the
services are in place but it doesn't check if anything about
characteristics and descriptors, also in the meantime you can issue
command as we see above, so it doesn't introduce extra delays so I
wonder why this is bothering you?
--
Luiz Augusto von Dentz
Hi Luiz,
On Thu, Nov 10, 2016 at 6:17 AM, Luiz Augusto von Dentz
<[email protected]> wrote:
> Hi Petri,
>
> On Wed, Nov 9, 2016 at 9:39 PM, Petri Gynther <[email protected]> wrote:
>> Hi linux-bluetooth:
>>
>> I'm seeing the following issue with BlueZ 5.43 and Linux 4.4.30.
>>
>> When a previously bonded HoG remote control reconnects to BlueZ 5.43
>> host, BlueZ goes ahead and re-discovers the primary services of the
>> bonded remote again and again on every reconnect.
>>
>> Why is this necessary? Shouldn't this information be cached on the
>> initial pairing/bonding, and a reconnect can get this information from
>> the relevant persistent file, rather than wasting BLE airtime and
>> delaying the reconnect?
>>
>
> IF, and only if, the cache is restored properly then yes it will work
> as you said, but bt_hog is not yet using the gatt_db so it might
> rediscover the handles anyway, this happens only once though.
>
>>
>>
>> In the above log, I see that MTU exchange takes place:
>> 15,148467,14484676000,-;bluez: bluetoothd[1985]:
>> src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
>>
>> Looking at the relevant code in src/shared/gatt-client.c, function
>> exchange_mtu_cb():
>>
>> util_debug(client->debug_callback, client->debug_data,
>> "MTU exchange complete, with MTU: %u",
>> bt_att_get_mtu(client->att));
>>
>> discover:
>> client->discovery_req = bt_gatt_discover_all_primary_services(
>> client->att, NULL,
>> discover_primary_cb,
>> discovery_op_ref(op),
>> discovery_op_unref);
>>
>>
>> The call to bt_gatt_discover_all_primary_services() is unconditional,
>> whether the device was previously bonded or not.
>
> This does range validation in case service changed is not properly
> implemented this will attempt to figure out if there are any changes
> in the database, but note that it will stop in here:
>
> attr = gatt_db_insert_service(client->db, start, &uuid, true,
> end - start + 1);
> if (!attr) {
>
> So if the database already contain all the services it will no do more
> than one Read By Group Type.
>
> --
> Luiz Augusto von Dentz
I'm observing primary services re-discovery on every reconnect, even
on the first reconnect after the initial pairing.
Multiple Read By Group Type messages are sent to the remote, until all
primary services have been re-discovered.
The files D4:F5:13:xx:xx:xx/attributes and cache/D4:F5:13:xx:xx:xx
exist and contain valid data.
Here is the log for the initial pairing:
15,15255,744664000,-;bluez: bluetoothd[2346]:
src/device.c:bonding_request_new() Requesting bonding for
D4:F5:13:xx:xx:xx
15,15256,744664000,-;bluez: bluetoothd[2346]: src/agent.c:agent_ref()
0x51c600: ref=3
15,15257,744664000,-;bluez: bluetoothd[2346]:
src/agent.c:agent_unref() 0x51c600: ref=2
15,15258,744664000,-;bluez: bluetoothd[2346]: src/adapter.c:suspend_discovery()
15,15259,744667000,-;bluez: bluetoothd[2346]:
src/adapter.c:adapter_bonding_attempt() hci0 bdaddr D4:F5:13:xx:xx:xx
type 1 io_cap 0x03
15,15306,744819000,-;bluez: bluetoothd[2346]:
src/adapter.c:connected_callback() hci0 device D4:F5:13:xx:xx:xx
connected eir_len 30
15,15313,744822000,-;bluez: bluetoothd[2346]:
src/adapter.c:connected_callback() device 0x518440 paired 0 bonded 0
bonding 1
15,15314,744822000,-;bluez: bluetoothd[2346]:
src/device.c:device_set_class() /org/bluez/hci0/dev_D4_F5_13_xx_xx_xx
0x20050C
15,15387,744928000,-;bluez: bluetoothd[2346]:
src/gatt-database.c:connect_cb() New incoming LE ATT connection
15,15388,744947000,-;bluez: bluetoothd[2346]:
attrib/gattrib.c:g_attrib_ref() 0x5159d8: g_attrib_ref=1
15,15389,744947000,-;bluez: bluetoothd[2346]:
src/device.c:load_gatt_db() Restoring D4:F5:13:xx:xx:xx gatt database
from file
15,15390,744948000,-;bluez: bluetoothd[2346]: No cache for D4:F5:13:xx:xx:xx
15,15394,744951000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:btd_gatt_client_connected() Device connected.
15,15413,745068000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
15,15442,745101000,-;bluez: bluetoothd[2346]:
src/adapter.c:new_irk_callback() hci0 new IRK for D4:F5:13:xx:xx:xx
RPA 00:00:00:00:00:00
15,15466,745120000,-;bluez: bluetoothd[2346]:
src/adapter.c:new_csrk_callback() hci0 new CSRK for D4:F5:13:xx:xx:xx
type 1
15,15489,745161000,-;bluez: bluetoothd[2346]:
src/adapter.c:new_csrk_callback() hci0 new CSRK for D4:F5:13:xx:xx:xx
type 0
15,15490,745177000,-;bluez: bluetoothd[2346]:
src/adapter.c:new_long_term_key_callback() hci0 new LTK for
D4:F5:13:xx:xx:xx type 0 enc_size 16
15,15491,745193000,-;bluez: bluetoothd[2346]: src/device.c:device_set_bonded()
15,15492,745193000,-;bluez: bluetoothd[2346]:
src/device.c:device_bonding_complete() bonding 0x51a458 status 0x00
15,15493,745194000,-;bluez: bluetoothd[2346]:
src/device.c:device_bonding_complete() Proceeding with service
discovery
15,15494,745194000,-;bluez: bluetoothd[2346]:
src/agent.c:agent_unref() 0x51c600: ref=1
15,15496,745196000,-;bluez: bluetoothd[2346]: src/adapter.c:resume_discovery()
15,15500,745198000,-;bluez: bluetoothd[2346]:
src/adapter.c:new_long_term_key_callback() hci0 new LTK for
D4:F5:13:xx:xx:xx type 0 enc_size 16
15,15505,745216000,-;bluez: bluetoothd[2346]: src/device.c:device_set_bonded()
15,15506,745216000,-;bluez: bluetoothd[2346]:
src/device.c:device_bonding_complete() bonding (nil) status 0x00
15,15507,745217000,-;bluez: bluetoothd[2346]: src/adapter.c:resume_discovery()
15,15514,745230000,-;bluez: bluetoothd[2346]:
src/adapter.c:pair_device_complete() Success (0x00)
15,15515,745230000,-;bluez: bluetoothd[2346]:
src/adapter.c:bonding_attempt_complete() hci0 bdaddr D4:F5:13:xx:xx:xx
type 1 status 0x0
15,15516,745233000,-;bluez: bluetoothd[2346]:
src/device.c:device_bonding_complete() bonding (nil) status 0x00
15,15517,745233000,-;bluez: bluetoothd[2346]: src/adapter.c:resume_discovery()
15,15548,745375000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Primary services found: 9
15,15549,745375000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0001, end: 0x000b, uuid:
00001800-0000-1000-8000-00805f9b34fb
15,15550,745376000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x000c, end: 0x000f, uuid:
00001801-0000-1000-8000-00805f9b34fb
15,15551,745377000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0010, end: 0x0022, uuid:
0000180a-0000-1000-8000-00805f9b34fb
15,15552,745380000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0023, end: 0x0028, uuid:
0000180f-0000-1000-8000-00805f9b34fb
15,15553,745380000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0029, end: 0x002e, uuid:
00001813-0000-1000-8000-00805f9b34fb
15,15554,745381000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x002f, end: 0x0037, uuid:
0000fff0-0000-1000-8000-00805f9b34fb
15,15555,745384000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0038, end: 0x005c, uuid:
00001812-0000-1000-8000-00805f9b34fb
15,15556,745384000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x005d, end: 0x0070, uuid:
f000fef0-0451-4000-b000-000000000000
15,15557,745384000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0071, end: 0xffff, uuid:
f000ffc0-0451-4000-b000-000000000000
15,15571,745472000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Secondary service discovery failed. ATT
ECODE: 0x10
15,15672,745685000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Included services found: 1
15,15673,745685000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0039, start: 0x0023, end:
0x0028,uuid: 0000180f-0000-1000-8000-0080
15,15753,745903000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 5
15,15754,745904000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0002, end: 0x0003, value: 0x0003,
props: 0x02, uuid: 00002a00-0000-1
15,15755,745905000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0004, end: 0x0005, value: 0x0005,
props: 0x02, uuid: 00002a01-0000-1
15,15756,745906000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0006, end: 0x0007, value: 0x0007,
props: 0x0a, uuid: 00002a02-0000-1
15,15757,745907000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0008, end: 0x0009, value: 0x0009,
props: 0x08, uuid: 00002a03-0000-1
15,15758,745912000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x000a, end: 0x000b, value: 0x000b,
props: 0x02, uuid: 00002a04-0000-1
15,15789,746112000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 1
15,15790,746113000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x000d, end: 0x000f, value: 0x000e,
props: 0x20, uuid: 00002a05-0000-1
15,15798,746134000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,15804,746134000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x000f, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,15875,746292000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 9
15,15876,746294000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0011, end: 0x0012, value: 0x0012,
props: 0x02, uuid: 00002a23-0000-1
15,15877,746294000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0013, end: 0x0014, value: 0x0014,
props: 0x02, uuid: 00002a24-0000-1
15,15878,746296000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0015, end: 0x0016, value: 0x0016,
props: 0x02, uuid: 00002a25-0000-1
15,15879,746296000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0017, end: 0x0018, value: 0x0018,
props: 0x02, uuid: 00002a26-0000-1
15,15880,746300000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0019, end: 0x001a, value: 0x001a,
props: 0x02, uuid: 00002a27-0000-1
15,15883,746304000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x001b, end: 0x001c, value: 0x001c,
props: 0x02, uuid: 00002a28-0000-1
15,15884,746307000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x001d, end: 0x001e, value: 0x001e,
props: 0x02, uuid: 00002a29-0000-1
15,15885,746307000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x001f, end: 0x0020, value: 0x0020,
props: 0x02, uuid: 00002a2a-0000-1
15,15886,746308000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0021, end: 0x0022, value: 0x0022,
props: 0x02, uuid: 00002a50-0000-1
15,15914,746423000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 1
15,15915,746424000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0024, end: 0x0028, value: 0x0025,
props: 0x12, uuid: 00002a19-0000-1
15,15932,746453000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 3
15,15933,746453000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0026, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,15934,746453000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0027, uuid:
00002908-0000-1000-8000-00805f9b34fb
15,15935,746455000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0028, uuid:
00002904-0000-1000-8000-00805f9b34fb
15,15960,746513000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 2
15,15962,746514000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x002a, end: 0x002b, value: 0x002b,
props: 0x04, uuid: 00002a4f-0000-1
15,15964,746515000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x002c, end: 0x002e, value: 0x002d,
props: 0x10, uuid: 00002a31-0000-1
15,15980,746535000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,15981,746536000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x002e, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16014,746904000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 3
15,16015,746904000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0030, end: 0x0032, value: 0x0031,
props: 0x1e, uuid: 0000fff1-0000-1
15,16016,746905000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0033, end: 0x0034, value: 0x0034,
props: 0x0a, uuid: 0000fff2-0000-1
15,16017,746909000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0035, end: 0x0037, value: 0x0036,
props: 0x12, uuid: 0000fff4-0000-1
15,16029,747004000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16031,747005000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0032, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16044,747124000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16045,747124000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0037, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16128,747343000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 12
15,16130,747343000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x003a, end: 0x003b, value: 0x003b,
props: 0x02, uuid: 00002a4a-0000-1
15,16132,747344000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x003c, end: 0x003d, value: 0x003d,
props: 0x04, uuid: 00002a4c-0000-1
15,16135,747345000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x003e, end: 0x003f, value: 0x003f,
props: 0x06, uuid: 00002a4e-0000-1
15,16137,747346000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0040, end: 0x0042, value: 0x0041,
props: 0x02, uuid: 00002a4b-0000-1
15,16139,747347000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0043, end: 0x0046, value: 0x0044,
props: 0x12, uuid: 00002a4d-0000-1
15,16141,747350000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0047, end: 0x004a, value: 0x0048,
props: 0x12, uuid: 00002a4d-0000-1
15,16142,747351000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x004b, end: 0x004e, value: 0x004c,
props: 0x12, uuid: 00002a4d-0000-1
15,16143,747355000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x004f, end: 0x0051, value: 0x0050,
props: 0x0e, uuid: 00002a4d-0000-1
15,16144,747356000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0052, end: 0x0054, value: 0x0053,
props: 0x12, uuid: 00002a22-0000-1
15,16145,747359000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0055, end: 0x0056, value: 0x0056,
props: 0x0e, uuid: 00002a32-0000-1
15,16146,747361000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0057, end: 0x0059, value: 0x0058,
props: 0x12, uuid: 00002a33-0000-1
15,16147,747363000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x005a, end: 0x005c, value: 0x005b,
props: 0x0a, uuid: 00002a4d-0000-1
15,16156,747526000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16157,747526000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0042, uuid:
00002907-0000-1000-8000-00805f9b34fb
15,16177,747635000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 2
15,16178,747638000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0045, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16179,747638000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0046, uuid:
00002908-0000-1000-8000-00805f9b34fb
15,16195,747744000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 2
15,16196,747744000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0049, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16197,747744000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x004a, uuid:
00002908-0000-1000-8000-00805f9b34fb
15,16213,747776000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 2
15,16214,747776000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x004d, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16215,747776000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x004e, uuid:
00002908-0000-1000-8000-00805f9b34fb
15,16225,747873000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16231,747874000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0051, uuid:
00002908-0000-1000-8000-00805f9b34fb
15,16244,747894000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16245,747894000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0054, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16258,747913000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16259,747913000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0059, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16272,747936000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16273,747936000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x005c, uuid:
00002908-0000-1000-8000-00805f9b34fb
15,16416,748556000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 9
15,16422,748563000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x005e, end: 0x005f, value: 0x005f,
props: 0x0a, uuid: f000fef1-0451-4
15,16423,748563000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0060, end: 0x0061, value: 0x0061,
props: 0x0a, uuid: f000fef2-0451-4
15,16424,748563000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0062, end: 0x0063, value: 0x0063,
props: 0x0a, uuid: f000fef3-0451-4
15,16425,748563000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0064, end: 0x0065, value: 0x0065,
props: 0x0a, uuid: f000fef4-0451-4
15,16426,748563000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0066, end: 0x0068, value: 0x0067,
props: 0x08, uuid: f000fef5-0451-4
15,16427,748565000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0069, end: 0x006a, value: 0x006a,
props: 0x0a, uuid: f000fef6-0451-4
15,16428,748565000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x006b, end: 0x006c, value: 0x006c,
props: 0x0a, uuid: f000fef7-0451-4
15,16429,748567000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x006d, end: 0x006e, value: 0x006e,
props: 0x0a, uuid: f000fef8-0451-4
15,16430,748572000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x006f, end: 0x0070, value: 0x0070,
props: 0x08, uuid: f000fef9-0451-4
15,16443,748665000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16444,748665000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0068, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16488,748827000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Characteristics found: 2
15,16489,748827000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0072, end: 0x0074, value: 0x0073,
props: 0x1c, uuid: f000ffc1-0451-4
15,16490,748827000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0075, end: 0xffff, value: 0x0076,
props: 0x1c, uuid: f000ffc2-0451-4
15,16505,748849000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16506,748849000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0074, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16534,748968000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Descriptors found: 1
15,16535,748968000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() handle: 0x0077, uuid:
00002902-0000-1000-8000-00805f9b34fb
15,16536,748968000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_client_ready_cb() status: success, error: 10
15,16537,748973000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
00001800-0000-1000-8000-00805f9b34fb
15,16538,748975000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
00001801-0000-1000-8000-00805f9b34fb
15,16539,748975000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
0000180a-0000-1000-8000-00805f9b34fb
15,16540,748978000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
0000180f-0000-1000-8000-00805f9b34fb
15,16541,748978000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
00001813-0000-1000-8000-00805f9b34fb
15,16542,748979000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
0000fff0-0000-1000-8000-00805f9b34fb
15,16543,748981000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
00001812-0000-1000-8000-00805f9b34fb
15,16544,748981000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
f000fef0-0451-4000-b000-000000000000
15,16545,748983000,-;bluez: bluetoothd[2346]:
src/device.c:update_gatt_uuids() UUID Added:
f000ffc0-0451-4000-b000-000000000000
15,16546,748987000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16554,748989000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:gap_probe() GAP profile probe (D4:F5:13:xx:xx:xx)
15,16555,748991000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x563210: device D4:F5:13:xx:xx:xx
profile gap-profile state changed: unavailable -> disconnected (0)
15,16556,748993000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:gap_accept() GAP profile accept (D4:F5:13:xx:xx:xx)
15,16558,748998000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a02-0000-1000-8000-00805f9b34fb
15,16559,749000000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a03-0000-1000-8000-00805f9b34fb
15,16560,749000000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a04-0000-1000-8000-00805f9b34fb
15,16561,749002000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x563210: device D4:F5:13:xx:xx:xx
profile gap-profile state changed: disconnected -> connected (0)
15,16563,749003000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16564,749006000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16567,749011000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564370: device D4:F5:13:xx:xx:xx
profile deviceinfo state changed: unavailable -> disconnected (0)
15,16568,749015000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:deviceinfo_accept() deviceinfo
profile accept (D4:F5:13:xx:xx:xx)
15,16569,749018000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a23-0000-1000-8000-00805f9b34fb
15,16570,749019000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a24-0000-1000-8000-00805f9b34fb
15,16571,749021000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a25-0000-1000-8000-00805f9b34fb
15,16572,749023000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a26-0000-1000-8000-00805f9b34fb
15,16573,749024000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a27-0000-1000-8000-00805f9b34fb
15,16574,749024000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a28-0000-1000-8000-00805f9b34fb
15,16575,749026000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a29-0000-1000-8000-00805f9b34fb
15,16576,749027000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a2a-0000-1000-8000-00805f9b34fb
15,16577,749028000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564370: device D4:F5:13:xx:xx:xx
profile deviceinfo state changed: disconnected -> connected (0)
15,16578,749030000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16579,749031000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:batt_probe() BATT path
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx
15,16580,749032000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:batt_probe() BATT matched BATT_UUID
0000180f-0000-1000-8000-00805f9b34fb
15,16581,749037000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564408: device D4:F5:13:xx:xx:xx
profile Battery state changed: unavailable -> disconnected (0)
15,16582,749038000,-;bluez: bluetoothd[2346]:
src/device.c:device_set_auto_connect() D4:F5:13:xx:xx:xx auto connect:
1
15,16583,749041000,-;bluez: bluetoothd[2346]:
src/device.c:device_set_auto_connect() Already connected
15,16584,749043000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564408: device D4:F5:13:xx:xx:xx
profile Battery state changed: disconnected -> connected (0)
15,16585,749045000,-;bluez: bluetoothd[2346]:
src/service.c:btd_service_ref() 0x564408: ref=2
15,16586,749047000,-;bluez: bluetoothd[2346]:
plugins/policy.c:service_cb() Added Battery reconnect 0
15,16591,749062000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:batt_accept() BATT discovering
characteristics
15,16593,749066000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16595,749068000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:scan_param_probe() Scan Parameters Client
Driver profile probe (D4:F5:13:xx:xx:xx)
15,16596,749068000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564808: device D4:F5:13:xx:xx:xx
profile Scan Parameters Client Driver state changed: unavailable ->
disconnected (0)
15,16598,749075000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:scan_param_accept() Scan Parameters Client
Driver profile accept (D4:F5:13:xx:xx:xx)
15,16600,749077000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:handle_iwin() Scan Interval Window handle:
0x002b
15,16601,749079000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:handle_refresh() Scan Refresh handle: 0x002d
15,16602,749081000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564808: device D4:F5:13:xx:xx:xx
profile Scan Parameters Client Driver state changed: disconnected ->
connected (0)
15,16610,749141000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16612,749148000,-;bluez: bluetoothd[2346]:
profiles/input/hog.c:hog_probe() path
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx
15,16613,749149000,-;bluez: bluetoothd[2346]:
profiles/input/hog.c:hog_device_new() name=xxxxxx vendor=0x471,
product=0x2210, version=0x0
15,16614,749167000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564ba0: device D4:F5:13:xx:xx:xx
profile input-hog state changed: unavailable -> disconnected (0)
15,16615,749167000,-;bluez: bluetoothd[2346]:
src/device.c:device_set_auto_connect() D4:F5:13:xx:xx:xx auto connect:
1
15,16616,749171000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:bt_hog_attach() HoG discovering
characteristics
15,16617,749173000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564ba0: device D4:F5:13:xx:xx:xx
profile input-hog state changed: disconnected -> connected (0)
15,16618,749180000,-;bluez: bluetoothd[2346]:
src/service.c:btd_service_ref() 0x564ba0: ref=2
15,16619,749181000,-;bluez: bluetoothd[2346]:
plugins/policy.c:service_cb() Added input-hog reconnect 0
15,16620,749183000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16621,749189000,-;bluez: bluetoothd[2346]:
src/device.c:device_probe_profiles() Probing profiles for device
D4:F5:13:xx:xx:xx
15,16622,749196000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_probe() OAD path
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx
15,16623,749198000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_probe() OAD matched OAD_UUID
f000ffc0-0451-4000-b000-000000000000
15,16624,749198000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564f60: device D4:F5:13:xx:xx:xx
profile OAD state changed: unavailable -> disconnected (0)
15,16625,749199000,-;bluez: bluetoothd[2346]:
src/device.c:device_set_auto_connect() D4:F5:13:xx:xx:xx auto connect:
1
15,16626,749201000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564f60: device D4:F5:13:xx:xx:xx
profile OAD state changed: disconnected -> connected (0)
15,16627,749202000,-;bluez: bluetoothd[2346]:
src/service.c:btd_service_ref() 0x564f60: ref=2
15,16628,749206000,-;bluez: bluetoothd[2346]:
plugins/policy.c:service_cb() Added OAD reconnect 0
15,16629,749208000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_accept() OAD discovering characteristics
15,16630,749210000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:btd_gatt_client_ready() GATT client ready
15,16631,749212000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:create_services() Exporting objects for GATT
services: D4:F5:13:xx:xx:xx
15,16632,749212000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:service_create() Exported GATT service:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service000c
15,16633,749214000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service000c/char000d
15,16635,749221000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:descriptor_create() Exported GATT characteristic
descriptor: /org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service000c/char000d/desc000f
15,16636,749225000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:service_create() Exported GATT service:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010
15,16637,749226000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char0011
15,16638,749227000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char0013
15,16639,749228000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char0015
15,16640,749229000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char0017
15,16641,749233000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char0019
15,16642,749237000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char001b
15,16643,749240000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char001d
15,16644,749247000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char001f
15,16645,749249000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service0010/char0021
15,16646,749250000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:service_create() Exported GATT service:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d
15,16647,749252000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char005e
15,16648,749257000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char0060
15,16649,749259000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char0062
15,16650,749262000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char0064
15,16651,749265000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char0066
15,16652,749268000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:descriptor_create() Exported GATT characteristic
descriptor: /org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char0066/desc0068
15,16653,749273000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char0069
15,16654,749275000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char006b
15,16655,749277000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char006d
15,16656,749281000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:characteristic_create() Exported GATT
characteristic:
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx/service005d/char006f
15,16657,749283000,-;bluez: bluetoothd[2346]:
src/device.c:device_svc_resolved()
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx err 0
15,16669,749406000,-;bluez: bluetoothd[2346]:
src/adapter.c:add_device_complete() D4:F5:13:xx:xx:xx (1) added to
kernel connect list
15,16685,749474000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Registered handler for "Service Changed": 1
15,16697,749493000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:read_device_name_cb() GAP Device Name: xxxxxx
15,16698,749494000,-;bluez: bluetoothd[2346]:
src/device.c:btd_device_device_set_name()
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx xxxxxx
15,16709,749512000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x03c0
15,16726,749565000,-;bluez: bluetoothd[2346]:
src/device.c:btd_device_set_trusted() trusted 1
15,16750,749663000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
notification enabled
15,16817,749945000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:char_discovered_cb() BATT inspecting
characteristics
15,16818,749945000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:char_discovered_cb() BATT found
BATT_LEVEL_UUID value_handle=0x0025
15,16872,750055000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:level_read_char_cb() BATT level=100
15,16932,750307000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_char_discovered_cb() OAD inspecting
characteristics
15,16933,750307000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_char_discovered_cb() OAD found
OAD_IMG_IDENTITY_UUID value_handle=0x0073
15,16934,750309000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_discover_desc() OAD discovering descriptors
start=0x0074 end=0x0074
15,16935,750310000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_char_discovered_cb() OAD found
OAD_IMG_BLOCK_UUID value_handle=0x0076
15,16936,750312000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_discover_desc() OAD discovering descriptors
start=0x0077 end=0xffff
15,16972,750473000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_desc_discovered_cb() OAD found
OAD_IMG_IDENTITY_UUID ccc_handle=0x0074
15,16999,750524000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() HoG inspecting
characteristics
15,17000,750524000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x003a UUID:
00002a4a-0000-1000-8000-00805f9b34fb properties: 02
15,17001,750527000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x003c UUID:
00002a4c-0000-1000-8000-00805f9b34fb properties: 04
15,17002,750527000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x003e UUID:
00002a4e-0000-1000-8000-00805f9b34fb properties: 06
15,17003,750527000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x0040 UUID:
00002a4b-0000-1000-8000-00805f9b34fb properties: 02
15,17009,750529000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() HoG discovering report
map
15,17010,750530000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x0043 UUID:
00002a4d-0000-1000-8000-00805f9b34fb properties: 12
15,17011,750531000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x0047 UUID:
00002a4d-0000-1000-8000-00805f9b34fb properties: 12
15,17012,750532000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x004b UUID:
00002a4d-0000-1000-8000-00805f9b34fb properties: 12
15,17013,750533000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x004f UUID:
00002a4d-0000-1000-8000-00805f9b34fb properties: 0e
15,17014,750534000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x0052 UUID:
00002a22-0000-1000-8000-00805f9b34fb properties: 12
15,17015,750535000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x0055 UUID:
00002a32-0000-1000-8000-00805f9b34fb properties: 0e
15,17016,750536000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x0057 UUID:
00002a33-0000-1000-8000-00805f9b34fb properties: 12
15,17017,750537000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:char_discovered_cb() 0x005a UUID:
00002a4d-0000-1000-8000-00805f9b34fb properties: 0a
15,17018,750542000,-;bluez: bluetoothd[2346]:
attrib/gattrib.c:g_attrib_ref() 0x5159d8: g_attrib_ref=21
15,17030,750633000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_desc_discovered_cb() OAD found
OAD_IMG_BLOCK_UUID ccc_handle=0x0077
15,17181,751092000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:proto_mode_read_cb() HoG is operating in
Report Protocol Mode
15,17195,751113000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:info_read_cb() bcdHID: 0x0111 bCountryCode:
0x00 Flags: 0x01
15,17216,751164000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:external_report_reference_cb() External
report reference read, external report characteristic UUID: 0x2a19
15,17226,751184000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_reference_cb() Report 0x0044: id 0x01
type input
15,17237,751204000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_reference_cb() Report 0x0048: id 0x02
type input
15,17251,751224000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_reference_cb() Report 0x004c: id 0x03
type input
15,17262,751244000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_reference_cb() Report 0x0050: id 0x00
type output
15,17270,751262000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_reference_cb() Report 0x005b: id 0x00
type feature
15,17338,751382000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_ccc_written_cb() Report characteristic
descriptor written: notifications enabled
15,17349,751404000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_ccc_written_cb() Report characteristic
descriptor written: notifications enabled
15,17360,751423000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_ccc_written_cb() Report characteristic
descriptor written: notifications enabled
15,17386,751547000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() HoG inspecting report
map
15,17387,751547000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() Report MAP:
15,17388,751547000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 05 01
15,17389,751547000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 09 06
15,17390,751548000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() a1 01
15,17391,751549000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 85 02
15,17392,751549000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 05 07
15,17393,751550000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 19 e0
15,17394,751551000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 29 e7
15,17395,751554000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 15 00
15,17396,751554000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 25 01
15,17397,751558000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 01
15,17398,751560000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 08
15,17399,751561000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 81 02
15,17400,751566000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 01
15,17401,751566000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 08
15,17402,751567000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 81 01
15,17403,751568000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 05
15,17404,751569000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 01
15,17405,751570000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 05 08
15,17406,751571000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 19 01
15,17408,751574000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 29 05
15,17409,751578000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 91 02
15,17410,751579000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 01
15,17411,751581000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 03
15,17412,751585000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 91 01
15,17413,751586000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 06
15,17414,751589000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 08
15,17415,751590000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 15 00
15,17416,751591000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 25 73
15,17417,751596000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 05 07
15,17418,751596000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 19 00
15,17419,751598000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 29 73
15,17420,751600000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 81 00
15,17421,751602000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() c0
15,17422,751603000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 05 0c
15,17423,751607000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 09 01
15,17424,751609000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() a1 01
15,17425,751613000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 85 03
15,17426,751613000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 05 0c
15,17427,751615000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() a1 02
15,17428,751615000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 19 00
15,17429,751617000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 2a 3c 02
15,17430,751617000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 15 00
15,17431,751620000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 26 3c 02
15,17432,751620000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 01
15,17433,751622000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 10
15,17434,751623000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 81 00
15,17435,751625000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() c0
15,17436,751626000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() c0
15,17437,751628000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 06 00 ff
15,17438,751629000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 09 07
15,17439,751631000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() a1 01
15,17440,751633000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 85 81
15,17441,751635000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 19 00
15,17442,751638000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 2a ff 00
15,17443,751647000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 15 00
15,17444,751647000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 26 ff 00
15,17445,751649000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 75 08
15,17446,751651000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 95 01
15,17447,751652000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() 81 02
15,17448,751652000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() c0
15,17451,751664000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_map_read_cb() HoG created uHID device
15,17465,752003000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_upgrade_timer() OAD timer fired
15,17466,752003000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_enable_notify() OAD enabling notify for
OAD_IMG_IDENTITY_UUID
15,17467,752003000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_enable_notify() OAD enabling notify for
OAD_IMG_BLOCK_UUID
15,17488,752062000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_check_fwversion() OAD sending fw version
request
15,17509,752104000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_check_for_upgrade() OAD TI firmware is up to
date
15,17510,752107000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_check_for_upgrade() OAD GP firmware is up to
date
15,17511,752109000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_check_for_upgrade() OAD next check is in 28800
seconds
15,17548,755028000,-;bluez: bluetoothd[2346]:
src/adapter.c:new_conn_param() hci0 D4:F5:13:xx:xx:xx (1) min 0x0008
max 0x0008 latency 0x0032 timeout 0x01f4
15,17565,755036000,-;bluez: bluetoothd[2346]: src/adapter.c:store_conn_param()
15,17581,755058000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
15,17594,755145000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
15,17610,755375000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
15,17619,755483000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
Then, the remote disconnects to save battery:
15,18130,815801000,-;bluez: bluetoothd[2346]:
src/adapter.c:dev_disconnected() Device D4:F5:13:xx:xx:xx
disconnected, reason 3
15,18131,815801000,-;bluez: bluetoothd[2346]:
src/adapter.c:dev_disconnected() device 0x518440 paired 1 bonded 1
bonding 0
15,18132,815802000,-;bluez: bluetoothd[2346]:
src/adapter.c:adapter_remove_connection()
15,18133,815802000,-;bluez: bluetoothd[2346]:
plugins/policy.c:disconnect_cb() reason 3
15,18134,815804000,-;bluez: bluetoothd[2346]:
src/adapter.c:bonding_attempt_complete() hci0 bdaddr D4:F5:13:xx:xx:xx
type 1 status 0xe
15,18135,815804000,-;bluez: bluetoothd[2346]:
src/device.c:device_bonding_complete() bonding (nil) status 0x0e
15,18136,815804000,-;bluez: bluetoothd[2346]:
src/device.c:device_bonding_failed() status 14
15,18137,815805000,-;bluez: bluetoothd[2346]: src/adapter.c:resume_discovery()
15,18138,815807000,-;bluez: bluetoothd[2346]: src/device.c:att_disconnected_cb()
15,18139,815808000,-;bluez: bluetoothd[2346]:
src/device.c:att_disconnected_cb() Connection reset by peer (131)
15,18140,815808000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x563210: device D4:F5:13:xx:xx:xx
profile gap-profile state changed: connected -> disconnecting (0)
15,18141,815810000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x563210: device D4:F5:13:xx:xx:xx
profile gap-profile state changed: disconnecting -> disconnected (0)
15,18142,815810000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564370: device D4:F5:13:xx:xx:xx
profile deviceinfo state changed: connected -> disconnecting (0)
15,18149,815810000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564370: device D4:F5:13:xx:xx:xx
profile deviceinfo state changed: disconnecting -> disconnected (0)
15,18150,815811000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564408: device D4:F5:13:xx:xx:xx
profile Battery state changed: connected -> disconnecting (0)
15,18151,815811000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564408: device D4:F5:13:xx:xx:xx
profile Battery state changed: disconnecting -> disconnected (0)
15,18152,815813000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564808: device D4:F5:13:xx:xx:xx
profile Scan Parameters Client Driver state changed: connected ->
disconnecting (0)
15,18153,815814000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564808: device D4:F5:13:xx:xx:xx
profile Scan Parameters Client Driver state changed: disconnecting ->
disconnected (0)
15,18156,815816000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564ba0: device D4:F5:13:xx:xx:xx
profile input-hog state changed: connected -> disconnecting (0)
15,18157,815817000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564ba0: device D4:F5:13:xx:xx:xx
profile input-hog state changed: disconnecting -> disconnected (0)
15,18158,815818000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564f60: device D4:F5:13:xx:xx:xx
profile OAD state changed: connected -> disconnecting (0)
15,18159,815819000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564f60: device D4:F5:13:xx:xx:xx
profile OAD state changed: disconnecting -> disconnected (0)
15,18169,815827000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected.
Cleaning up.
15,18170,815828000,-;bluez: bluetoothd[2346]:
attrib/gattrib.c:g_attrib_unref() 0x5159d8: g_attrib_unref=0
And here is the first reconnect:
15,18345,832482000,-;bluez: bluetoothd[2346]:
src/adapter.c:connected_callback() hci0 device D4:F5:13:xx:xx:xx
connected eir_len 0
15,18352,832483000,-;bluez: bluetoothd[2346]:
src/adapter.c:connected_callback() device 0x518440 paired 1 bonded 1
bonding 0
15,18369,832511000,-;bluez: bluetoothd[2346]:
src/gatt-database.c:connect_cb() New incoming LE ATT connection
15,18370,832511000,-;bluez: bluetoothd[2346]:
src/device.c:device_attach_att() Elevating security level since LTK is
available
15,18384,832524000,-;bluez: bluetoothd[2346]:
attrib/gattrib.c:g_attrib_ref() 0x5159d8: g_attrib_ref=1
15,18385,832525000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:gap_accept() GAP profile accept (D4:F5:13:xx:xx:xx)
15,18386,832526000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a02-0000-1000-8000-00805f9b34fb
15,18387,832527000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a03-0000-1000-8000-00805f9b34fb
15,18388,832527000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:handle_characteristic() Unsupported characteristic:
00002a04-0000-1000-8000-00805f9b34fb
15,18389,832528000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x563210: device D4:F5:13:xx:xx:xx
profile gap-profile state changed: disconnected -> connected (0)
15,18391,832543000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:deviceinfo_accept() deviceinfo
profile accept (D4:F5:13:xx:xx:xx)
15,18392,832544000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a23-0000-1000-8000-00805f9b34fb
15,18393,832545000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a24-0000-1000-8000-00805f9b34fb
15,18394,832546000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a25-0000-1000-8000-00805f9b34fb
15,18395,832546000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a26-0000-1000-8000-00805f9b34fb
15,18396,832547000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a27-0000-1000-8000-00805f9b34fb
15,18397,832549000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a28-0000-1000-8000-00805f9b34fb
15,18398,832549000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a29-0000-1000-8000-00805f9b34fb
15,18399,832552000,-;bluez: bluetoothd[2346]:
profiles/deviceinfo/deviceinfo.c:handle_characteristic() Unsupported
characteristic: 00002a2a-0000-1000-8000-00805f9b34fb
15,18400,832557000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564370: device D4:F5:13:xx:xx:xx
profile deviceinfo state changed: disconnected -> connected (0)
15,18401,832558000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564408: device D4:F5:13:xx:xx:xx
profile Battery state changed: disconnected -> connected (0)
15,18402,832559000,-;bluez: bluetoothd[2346]:
plugins/policy.c:service_cb() Added Battery reconnect 0
15,18403,832563000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:scan_param_accept() Scan Parameters Client
Driver profile accept (D4:F5:13:xx:xx:xx)
15,18404,832563000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:handle_iwin() Scan Interval Window handle:
0x002b
15,18405,832565000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:handle_refresh() Scan Refresh handle: 0x002d
15,18406,832567000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564808: device D4:F5:13:xx:xx:xx
profile Scan Parameters Client Driver state changed: disconnected ->
connected (0)
15,18413,832579000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564ba0: device D4:F5:13:xx:xx:xx
profile input-hog state changed: disconnected -> connected (0)
15,18414,832579000,-;bluez: bluetoothd[2346]:
plugins/policy.c:service_cb() Added input-hog reconnect 0
15,18415,832579000,-;bluez: bluetoothd[2346]:
src/service.c:change_state() 0x564f60: device D4:F5:13:xx:xx:xx
profile OAD state changed: disconnected -> connected (0)
15,18416,832579000,-;bluez: bluetoothd[2346]:
plugins/policy.c:service_cb() Added OAD reconnect 0
15,18417,832579000,-;bluez: bluetoothd[2346]:
profiles/oad/oad.c:oad_is_time_for_upgrade_check() OAD not time for
upgrade check yet (28720 seconds left)
15,18418,832579000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:btd_gatt_client_connected() Device connected.
15,18441,832622000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
15,18447,832642000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:read_device_name_cb() GAP Device Name: xxxxxxxx
15,18463,832664000,-;bluez: bluetoothd[2346]:
profiles/gap/gas.c:read_appearance_cb() GAP Appearance: 0x03c0
15,18481,832702000,-;bluez: bluetoothd[2346]:
profiles/battery/battery.c:level_read_char_cb() BATT level=100
====
15,18491,832722000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
notification enabled
15,18649,834042000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Primary services found: 9
15,18650,834043000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0001, end: 0x000b, uuid:
00001800-0000-1000-8000-00805f9b34fb
15,18651,834043000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x000c, end: 0x000f, uuid:
00001801-0000-1000-8000-00805f9b34fb
15,18652,834043000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0010, end: 0x0022, uuid:
0000180a-0000-1000-8000-00805f9b34fb
15,18653,834045000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0023, end: 0x0028, uuid:
0000180f-0000-1000-8000-00805f9b34fb
15,18654,834046000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0029, end: 0x002e, uuid:
00001813-0000-1000-8000-00805f9b34fb
15,18655,834046000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x002f, end: 0x0037, uuid:
0000fff0-0000-1000-8000-00805f9b34fb
15,18656,834047000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0038, end: 0x005c, uuid:
00001812-0000-1000-8000-00805f9b34fb
15,18657,834049000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x005d, end: 0x0070, uuid:
f000fef0-0451-4000-b000-000000000000
15,18658,834050000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0071, end: 0xffff, uuid:
f000ffc0-0451-4000-b000-000000000000
15,18659,834053000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_client_ready_cb() status: success, error: 0
15,18660,834064000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:btd_gatt_client_ready() GATT client ready
15,18661,834066000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:create_services() Exporting objects for GATT
services: D4:F5:13:xx:xx:xx
15,18662,834066000,-;bluez: bluetoothd[2346]:
src/device.c:device_svc_resolved()
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx err 0
15,18673,834571000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Registered handler for "Service Changed": 2
15,18702,837932000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
15,18721,838033000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
15,18737,838262000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
15,18753,838353000,-;bluez: bluetoothd[2346]:
profiles/input/hog-lib.c:report_value_cb() HoG report (3 bytes)
Looking into btmon details after the line marked ====:
15,18491,832722000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
notification enabled
We can see that BlueZ issues a bunch of ATT: Read By Group Type
Requests to re-discover all primary services (0x2800):
15,18491,832722000,-;bluez: bluetoothd[2346]:
profiles/scanparam/scan.c:refresh_ccc_written_cb() Scan Refresh:
notification enabled
15,18492,832723000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:51.730522
15,18493,832725000,-;btmon: ATT: Read By Type Request (0x08) len 6
15,18494,832725000,-;btmon: Handle range: 0x002f-0x0037
15,18495,832725000,-;btmon: Attribute type: Characteristic (0x2803)
15,18496,832725000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:51.731128
15,18497,832726000,-;btmon: Num handles: 1
15,18498,832726000,-;btmon: Handle: 128
15,18499,832726000,-;btmon: Count: 1
15,18500,832733000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:51.739362
15,18501,832733000,-;btmon: Num handles: 1
15,18502,832733000,-;btmon: Handle: 128
15,18503,832733000,-;btmon: Count: 1
15,18504,832752000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
27 [hci0] 17:26:51.759357
15,18505,832753000,-;btmon: ATT: Read By Type Response (0x09) len 22
15,18506,832753000,-;btmon: Attribute data length: 7
15,18507,832753000,-;btmon: Attribute data list: 3 entries
15,18508,832753000,-;btmon: Handle: 0x0030
15,18509,832753000,-;btmon: Value: 1e3100f1ff
15,18510,832753000,-;btmon: Handle: 0x0033
15,18511,832753000,-;btmon: Value: 0a3400f2ff
15,18512,832753000,-;btmon: Handle: 0x0035
15,18513,832753000,-;btmon: Value: 123600f4ff
15,18514,832754000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:51.760043
15,18515,832754000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
15,18516,832754000,-;btmon: Handle range: 0x0001-0xffff
15,18517,832754000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,18518,832762000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:51.769346
15,18519,832762000,-;btmon: Num handles: 1
15,18520,832762000,-;btmon: Handle: 128
15,18521,832762000,-;btmon: Count: 1
15,18522,832782000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
24 [hci0] 17:26:51.789303
15,18523,832782000,-;btmon: ATT: Read By Group Type Response (0x11) len 19
15,18524,832782000,-;btmon: Attribute data length: 6
15,18525,832782000,-;btmon: Attribute group list: 3 entries
15,18526,832784000,-;btmon: Handle range: 0x0001-0x000b
15,18527,832784000,-;btmon: UUID: Generic Access Profile (0x1800)
15,18528,832784000,-;btmon: Handle range: 0x000c-0x000f
15,18529,832784000,-;btmon: UUID: Generic Attribute Profile (0x1801)
15,18530,832784000,-;btmon: Handle range: 0x0010-0x0022
15,18531,832784000,-;btmon: UUID: Device Information (0x180a)
15,18532,832784000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:51.790028
15,18533,832784000,-;btmon: ATT: Read By Type Request (0x08) len 6
15,18534,832784000,-;btmon: Handle range: 0x0036-0x0037
15,18535,832784000,-;btmon: Attribute type: Characteristic (0x2803)
15,18536,832792000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:51.799354
15,18537,832792000,-;btmon: Num handles: 1
15,18538,832792000,-;btmon: Handle: 128
15,18539,832792000,-;btmon: Count: 1
15,18540,832809000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
9 [hci0] 17:26:51.808179
15,18541,832809000,-;btmon: ATT: Error Response (0x01) len 4
15,18542,832809000,-;btmon: Read By Type Request (0x08)
15,18543,832809000,-;btmon: Handle: 0x0036
15,18544,832809000,-;btmon: Error: Attribute Not Found (0x0a)
15,18546,832811000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:51.810774
15,18547,832812000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
15,18548,832812000,-;btmon: Handle range: 0x0023-0xffff
15,18549,832812000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,18553,833321000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:52.328191
15,18554,833321000,-;btmon: Num handles: 1
15,18555,833321000,-;btmon: Handle: 128
15,18556,833321000,-;btmon: Count: 1
15,18558,833334000,-;btmon: > HCI Event: Vendor (0xff) plen 5
[hci0] 17:26:52.339515
15,18559,833334000,-;btmon: 05 80 00 09 00
.....
15,18560,833362000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
24 [hci0] 17:26:52.369478
15,18561,833363000,-;btmon: ATT: Read By Group Type Response (0x11) len 19
15,18562,833363000,-;btmon: Attribute data length: 6
15,18563,833363000,-;btmon: Attribute group list: 3 entries
15,18564,833364000,-;btmon: Handle range: 0x0023-0x0028
15,18565,833364000,-;btmon: UUID: Battery Service (0x180f)
15,18566,833364000,-;btmon: Handle range: 0x0029-0x002e
15,18567,833364000,-;btmon: UUID: Scan Parameters (0x1813)
15,18568,833364000,-;btmon: Handle range: 0x002f-0x0037
15,18569,833364000,-;btmon: UUID: Unknown (0xfff0)
15,18570,833364000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
9 [hci0] 17:26:52.370138
15,18571,833364000,-;btmon: ATT: Find Information Request (0x04) len 4
15,18572,833364000,-;btmon: Handle range: 0x0036-0x0037
15,18574,833371000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:52.378203
15,18575,833371000,-;btmon: Num handles: 1
15,18576,833371000,-;btmon: Handle: 128
15,18577,833371000,-;btmon: Count: 1
15,18578,833391000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
14 [hci0] 17:26:52.398166
15,18579,833391000,-;btmon: ATT: Find Information Response (0x05) len 9
15,18580,833392000,-;btmon: Format: UUID-16 (0x01)
15,18582,833394000,-;btmon: Handle: 0x0036
15,18583,833394000,-;btmon: UUID: Unknown (0xfff4)
15,18584,833394000,-;btmon: Handle: 0x0037
15,18585,833394000,-;btmon: UUID: Client Characteristic
Configuration (0x2902)
15,18586,833394000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
10 [hci0] 17:26:52.400735
15,18587,833394000,-;btmon: ATT: Write Request (0x12) len 5
15,18588,833394000,-;btmon: Handle: 0x0034
15,18589,833394000,-;btmon: Data: 030000
15,18591,833912000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:52.919397
15,18592,833912000,-;btmon: Num handles: 1
15,18593,833912000,-;btmon: Handle: 128
15,18594,833912000,-;btmon: Count: 1
15,18595,833931000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
5 [hci0] 17:26:52.938157
15,18596,833931000,-;btmon: ATT: Write Response (0x13) len 0
15,18597,833932000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:52.939032
15,18598,833932000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
15,18599,833932000,-;btmon: Handle range: 0x0038-0xffff
15,18600,833932000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,18601,833944000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:52.951628
15,18602,833944000,-;btmon: Num handles: 1
15,18603,833944000,-;btmon: Handle: 128
15,18604,833944000,-;btmon: Count: 1
15,18605,833959000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
12 [hci0] 17:26:52.966479
15,18606,833959000,-;btmon: ATT: Read By Group Type Response (0x11) len 7
15,18607,833960000,-;btmon: Attribute data length: 6
15,18608,833960000,-;btmon: Attribute group list: 1 entry
15,18609,833960000,-;btmon: Handle range: 0x0038-0x005c
15,18610,833960000,-;btmon: UUID: Human Interface Device (0x1812)
15,18611,833960000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
9 [hci0] 17:26:52.967113
15,18612,833960000,-;btmon: ATT: Write Request (0x12) len 4
15,18613,833960000,-;btmon: Handle: 0x0037
15,18614,833960000,-;btmon: Data: 0100
15,18615,833971000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:52.976999
15,18616,833971000,-;btmon: Num handles: 1
15,18617,833972000,-;btmon: Handle: 128
15,18618,833972000,-;btmon: Count: 1
15,18619,833979000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
5 [hci0] 17:26:52.986355
15,18620,833980000,-;btmon: ATT: Write Response (0x13) len 0
15,18621,833980000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:52.986894
15,18622,833980000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
15,18623,833980000,-;btmon: Handle range: 0x005d-0xffff
15,18624,833980000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,18625,833990000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:52.996610
15,18626,833990000,-;btmon: Num handles: 1
15,18627,833991000,-;btmon: Handle: 128
15,18628,833991000,-;btmon: Count: 1
15,18629,834013000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
26 [hci0] 17:26:53.019401
15,18630,834013000,-;btmon: ATT: Read By Group Type Response (0x11) len 21
15,18631,834013000,-;btmon: Attribute data length: 20
15,18632,834013000,-;btmon: Attribute group list: 1 entry
15,18633,834013000,-;btmon: Handle range: 0x005d-0x0070
15,18634,834013000,-;btmon: UUID: Vendor specific
(f000fef0-0451-4000-b000-000000000000)
15,18635,834013000,-;btmon: < ACL Data TX: Handle 128 flags 0x00 dlen
11 [hci0] 17:26:53.020026
15,18636,834013000,-;btmon: ATT: Read By Group Type Request (0x10) len 6
15,18637,834013000,-;btmon: Handle range: 0x0071-0xffff
15,18638,834013000,-;btmon: Attribute group type: Primary
Service (0x2800)
15,18639,834022000,-;btmon: > HCI Event: Number of Completed Packets
(0x13) plen 5 [hci0] 17:26:53.029922
15,18640,834022000,-;btmon: Num handles: 1
15,18641,834022000,-;btmon: Handle: 128
15,18642,834023000,-;btmon: Count: 1
15,18643,834042000,-;btmon: > ACL Data RX: Handle 128 flags 0x02 dlen
26 [hci0] 17:26:53.049348
15,18644,834042000,-;btmon: ATT: Read By Group Type Response (0x11) len 21
15,18645,834042000,-;btmon: Attribute data length: 20
15,18646,834042000,-;btmon: Attribute group list: 1 entry
15,18647,834042000,-;btmon: Handle range: 0x0071-0xffff
15,18648,834042000,-;btmon: UUID: Vendor specific
(f000ffc0-0451-4000-b000-000000000000)
15,18649,834042000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() Primary services found: 9
15,18650,834043000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0001, end: 0x000b, uuid:
00001800-0000-1000-8000-00805f9b34fb
15,18651,834043000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x000c, end: 0x000f, uuid:
00001801-0000-1000-8000-00805f9b34fb
15,18652,834043000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0010, end: 0x0022, uuid:
0000180a-0000-1000-8000-00805f9b34fb
15,18653,834045000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0023, end: 0x0028, uuid:
0000180f-0000-1000-8000-00805f9b34fb
15,18654,834046000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0029, end: 0x002e, uuid:
00001813-0000-1000-8000-00805f9b34fb
15,18655,834046000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x002f, end: 0x0037, uuid:
0000fff0-0000-1000-8000-00805f9b34fb
15,18656,834047000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0038, end: 0x005c, uuid:
00001812-0000-1000-8000-00805f9b34fb
15,18657,834049000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x005d, end: 0x0070, uuid:
f000fef0-0451-4000-b000-000000000000
15,18658,834050000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_debug() start: 0x0071, end: 0xffff, uuid:
f000ffc0-0451-4000-b000-000000000000
15,18659,834053000,-;bluez: bluetoothd[2346]:
src/device.c:gatt_client_ready_cb() status: success, error: 0
15,18660,834064000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:btd_gatt_client_ready() GATT client ready
15,18661,834066000,-;bluez: bluetoothd[2346]:
src/gatt-client.c:create_services() Exporting objects for GATT
services: D4:F5:13:xx:xx:xx
15,18662,834066000,-;bluez: bluetoothd[2346]:
src/device.c:device_svc_resolved()
/org/bluez/hci0/dev_D4_F5_13_xx_xx_xx err 0
The file "D4:F5:13:xx:xx:xx/attributes" exists and contains:
[1]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=1800
EndGroupHandle=11
[12]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=1801
EndGroupHandle=15
[16]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=180A
EndGroupHandle=34
[35]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=180F
EndGroupHandle=40
[41]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=1813
EndGroupHandle=46
[47]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=FFF0
EndGroupHandle=55
[56]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=1812
EndGroupHandle=92
[93]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=F000FEF004514000B000000000000000
EndGroupHandle=112
[113]
UUID=00002800-0000-1000-8000-00805f9b34fb
Value=F000FFC004514000B000000000000000
EndGroupHandle=65535
And, the file "cache/D4:F5:13:xx:xx:xx" exists and contains:
[Attributes]
0001=2800:000b:00001800-0000-1000-8000-00805f9b34fb
0002=2803:0003:02:00002a00-0000-1000-8000-00805f9b34fb
0004=2803:0005:02:00002a01-0000-1000-8000-00805f9b34fb
0006=2803:0007:0a:00002a02-0000-1000-8000-00805f9b34fb
0008=2803:0009:08:00002a03-0000-1000-8000-00805f9b34fb
000a=2803:000b:02:00002a04-0000-1000-8000-00805f9b34fb
000c=2800:000f:00001801-0000-1000-8000-00805f9b34fb
000d=2803:000e:20:00002a05-0000-1000-8000-00805f9b34fb
000f=00002902-0000-1000-8000-00805f9b34fb
0010=2800:0022:0000180a-0000-1000-8000-00805f9b34fb
0011=2803:0012:02:00002a23-0000-1000-8000-00805f9b34fb
0013=2803:0014:02:00002a24-0000-1000-8000-00805f9b34fb
0015=2803:0016:02:00002a25-0000-1000-8000-00805f9b34fb
0017=2803:0018:02:00002a26-0000-1000-8000-00805f9b34fb
0019=2803:001a:02:00002a27-0000-1000-8000-00805f9b34fb
001b=2803:001c:02:00002a28-0000-1000-8000-00805f9b34fb
001d=2803:001e:02:00002a29-0000-1000-8000-00805f9b34fb
001f=2803:0020:02:00002a2a-0000-1000-8000-00805f9b34fb
0021=2803:0022:02:00002a50-0000-1000-8000-00805f9b34fb
0023=2800:0028:0000180f-0000-1000-8000-00805f9b34fb
0024=2803:0025:12:00002a19-0000-1000-8000-00805f9b34fb
0026=00002902-0000-1000-8000-00805f9b34fb
0027=00002908-0000-1000-8000-00805f9b34fb
0028=00002904-0000-1000-8000-00805f9b34fb
0029=2800:002e:00001813-0000-1000-8000-00805f9b34fb
002a=2803:002b:04:00002a4f-0000-1000-8000-00805f9b34fb
002c=2803:002d:10:00002a31-0000-1000-8000-00805f9b34fb
002e=00002902-0000-1000-8000-00805f9b34fb
002f=2800:0037:0000fff0-0000-1000-8000-00805f9b34fb
0030=2803:0031:1e:0000fff1-0000-1000-8000-00805f9b34fb
0032=00002902-0000-1000-8000-00805f9b34fb
0033=2803:0034:0a:0000fff2-0000-1000-8000-00805f9b34fb
0035=2803:0036:12:0000fff4-0000-1000-8000-00805f9b34fb
0037=00002902-0000-1000-8000-00805f9b34fb
0038=2800:005c:00001812-0000-1000-8000-00805f9b34fb
0039=2802:0023:0028:0000180f-0000-1000-8000-00805f9b34fb
003a=2803:003b:02:00002a4a-0000-1000-8000-00805f9b34fb
003c=2803:003d:04:00002a4c-0000-1000-8000-00805f9b34fb
003e=2803:003f:06:00002a4e-0000-1000-8000-00805f9b34fb
0040=2803:0041:02:00002a4b-0000-1000-8000-00805f9b34fb
0042=00002907-0000-1000-8000-00805f9b34fb
0043=2803:0044:12:00002a4d-0000-1000-8000-00805f9b34fb
0045=00002902-0000-1000-8000-00805f9b34fb
0046=00002908-0000-1000-8000-00805f9b34fb
0047=2803:0048:12:00002a4d-0000-1000-8000-00805f9b34fb
0049=00002902-0000-1000-8000-00805f9b34fb
004a=00002908-0000-1000-8000-00805f9b34fb
004b=2803:004c:12:00002a4d-0000-1000-8000-00805f9b34fb
004d=00002902-0000-1000-8000-00805f9b34fb
004e=00002908-0000-1000-8000-00805f9b34fb
004f=2803:0050:0e:00002a4d-0000-1000-8000-00805f9b34fb
0051=00002908-0000-1000-8000-00805f9b34fb
0052=2803:0053:12:00002a22-0000-1000-8000-00805f9b34fb
0054=00002902-0000-1000-8000-00805f9b34fb
0055=2803:0056:0e:00002a32-0000-1000-8000-00805f9b34fb
0057=2803:0058:12:00002a33-0000-1000-8000-00805f9b34fb
0059=00002902-0000-1000-8000-00805f9b34fb
005a=2803:005b:0a:00002a4d-0000-1000-8000-00805f9b34fb
005c=00002908-0000-1000-8000-00805f9b34fb
005d=2800:0070:f000fef0-0451-4000-b000-000000000000
005e=2803:005f:0a:f000fef1-0451-4000-b000-000000000000
0060=2803:0061:0a:f000fef2-0451-4000-b000-000000000000
0062=2803:0063:0a:f000fef3-0451-4000-b000-000000000000
0064=2803:0065:0a:f000fef4-0451-4000-b000-000000000000
0066=2803:0067:08:f000fef5-0451-4000-b000-000000000000
0068=00002902-0000-1000-8000-00805f9b34fb
0069=2803:006a:0a:f000fef6-0451-4000-b000-000000000000
006b=2803:006c:0a:f000fef7-0451-4000-b000-000000000000
006d=2803:006e:0a:f000fef8-0451-4000-b000-000000000000
006f=2803:0070:08:f000fef9-0451-4000-b000-000000000000
0071=2800:ffff:f000ffc0-0451-4000-b000-000000000000
0072=2803:0073:1c:f000ffc1-0451-4000-b000-000000000000
0074=00002902-0000-1000-8000-00805f9b34fb
0075=2803:0076:1c:f000ffc2-0451-4000-b000-000000000000
0077=00002902-0000-1000-8000-00805f9b34fb
Hi Petri,
On Wed, Nov 9, 2016 at 9:39 PM, Petri Gynther <[email protected]> wrote:
> Hi linux-bluetooth:
>
> I'm seeing the following issue with BlueZ 5.43 and Linux 4.4.30.
>
> When a previously bonded HoG remote control reconnects to BlueZ 5.43
> host, BlueZ goes ahead and re-discovers the primary services of the
> bonded remote again and again on every reconnect.
>
> Why is this necessary? Shouldn't this information be cached on the
> initial pairing/bonding, and a reconnect can get this information from
> the relevant persistent file, rather than wasting BLE airtime and
> delaying the reconnect?
>
IF, and only if, the cache is restored properly then yes it will work
as you said, but bt_hog is not yet using the gatt_db so it might
rediscover the handles anyway, this happens only once though.
>
>
> In the above log, I see that MTU exchange takes place:
> 15,148467,14484676000,-;bluez: bluetoothd[1985]:
> src/device.c:gatt_debug() MTU exchange complete, with MTU: 23
>
> Looking at the relevant code in src/shared/gatt-client.c, function
> exchange_mtu_cb():
>
> util_debug(client->debug_callback, client->debug_data,
> "MTU exchange complete, with MTU: %u",
> bt_att_get_mtu(client->att));
>
> discover:
> client->discovery_req = bt_gatt_discover_all_primary_services(
> client->att, NULL,
> discover_primary_cb,
> discovery_op_ref(op),
> discovery_op_unref);
>
>
> The call to bt_gatt_discover_all_primary_services() is unconditional,
> whether the device was previously bonded or not.
This does range validation in case service changed is not properly
implemented this will attempt to figure out if there are any changes
in the database, but note that it will stop in here:
attr = gatt_db_insert_service(client->db, start, &uuid, true,
end - start + 1);
if (!attr) {
So if the database already contain all the services it will no do more
than one Read By Group Type.
--
Luiz Augusto von Dentz
Hi Jos=C3=A9,
On Fri, Dec 9, 2016 at 12:43 AM, Jos=C3=A9 Bollo <[email protected]> wrote=
:
> Hi Petri,
>
> This is perhaps related to the question I asked yesterday.
> Where can I find your 4 patches?
>
The patches are already applied on upstream BlueZ:
shared/gatt-client: Fix discover_primary_cb()
shared/gatt-client: Fix discover_secondary_cb()
shared/gatt-db: Make gatt_db_clear call gatt_db_clear_range
shared/gatt-client: Don't clear db in case of errors
> Best regards
> Jos=C3=A9 Bollo
> Jos=C3=A9 Bollo - Senior Software Engineer
> http://www.iot.bzh
>
>
>
> 2016-12-08 22:52 GMT+01:00 Petri Gynther <[email protected]>:
>> Hi Luiz,
>>
>> On Fri, Dec 2, 2016 at 3:56 AM, Luiz Augusto von Dentz
>> <[email protected]> wrote:
>>> Hi Petri,
>>>
>>> On Thu, Dec 1, 2016 at 11:12 PM, Petri Gynther <[email protected]> wr=
ote:
>>>> However, in this case, I think this handling is correct.
>>>> load_gatt_db() showed "No cache for LEFQAU", so BlueZ has to
>>>> re-discover everything from the device over BLE.
>>>> But, since the device disconnected in the middle of discovery, BlueZ
>>>> couldn't fully populate the GATT DB and has to clean it.
>>>> If the device didn't disconnect so quickly, this would have most likel=
y worked.
>>>>
>>>>> But I do agree that we should not reset the db if that was populated
>>>>> already, so I will try to fix that.
>>>>
>>>> Yes, once BlueZ does not reset the GATT DB on failed reconnects, this
>>>> problem will be solved.
>>>
>>> Please check if everything is alright when using upstream, it should
>>> clear the database anymore if we get an early disconnect.
>>
>> I applied my 2 patches and your 2 patches on top of 5.43.
>>
>> GATT DB is no longer destroyed on reconnection errors, so that's excelle=
nt.
>>
>> However, we are still seeing reconnect problems, but not GATT DB related=
:
>> bluez: bluetoothd[17780]:
>> src/gatt-client.c:btd_gatt_client_connected() Device connected.
>> bluez: bluetoothd[17780]: profiles/gap/gas.c:read_device_name_cb()
>> Reading device name failed with ATT error: 0
>> bluez: bluetoothd[17780]: profiles/gap/gas.c:read_appearance_cb()
>> Reading appearance failed with ATT error: 0
>> bluez: bluetoothd[17780]: Error reading PNP_ID value: Unexpected error c=
ode
>> bluez: bluetoothd[17780]: BATT level_read_char_cb failed: Request
>> attribute has encountered an unlikely error
>>
>> We are still investigating this. Likely a firmware issue on the remote.
>>
>>>
>>>
>>> --
>>> Luiz Augusto von Dentz
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-bluetoot=
h" in
>> the body of a message to [email protected]
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
Hi Petri,
This is perhaps related to the question I asked yesterday.
Where can I find your 4 patches?
Best regards
Jos=C3=A9 Bollo
Jos=C3=A9 Bollo - Senior Software Engineer
http://www.iot.bzh
2016-12-08 22:52 GMT+01:00 Petri Gynther <[email protected]>:
> Hi Luiz,
>
> On Fri, Dec 2, 2016 at 3:56 AM, Luiz Augusto von Dentz
> <[email protected]> wrote:
>> Hi Petri,
>>
>> On Thu, Dec 1, 2016 at 11:12 PM, Petri Gynther <[email protected]> wro=
te:
>>> However, in this case, I think this handling is correct.
>>> load_gatt_db() showed "No cache for LEFQAU", so BlueZ has to
>>> re-discover everything from the device over BLE.
>>> But, since the device disconnected in the middle of discovery, BlueZ
>>> couldn't fully populate the GATT DB and has to clean it.
>>> If the device didn't disconnect so quickly, this would have most likely=
worked.
>>>
>>>> But I do agree that we should not reset the db if that was populated
>>>> already, so I will try to fix that.
>>>
>>> Yes, once BlueZ does not reset the GATT DB on failed reconnects, this
>>> problem will be solved.
>>
>> Please check if everything is alright when using upstream, it should
>> clear the database anymore if we get an early disconnect.
>
> I applied my 2 patches and your 2 patches on top of 5.43.
>
> GATT DB is no longer destroyed on reconnection errors, so that's excellen=
t.
>
> However, we are still seeing reconnect problems, but not GATT DB related:
> bluez: bluetoothd[17780]:
> src/gatt-client.c:btd_gatt_client_connected() Device connected.
> bluez: bluetoothd[17780]: profiles/gap/gas.c:read_device_name_cb()
> Reading device name failed with ATT error: 0
> bluez: bluetoothd[17780]: profiles/gap/gas.c:read_appearance_cb()
> Reading appearance failed with ATT error: 0
> bluez: bluetoothd[17780]: Error reading PNP_ID value: Unexpected error co=
de
> bluez: bluetoothd[17780]: BATT level_read_char_cb failed: Request
> attribute has encountered an unlikely error
>
> We are still investigating this. Likely a firmware issue on the remote.
>
>>
>>
>> --
>> Luiz Augusto von Dentz
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth=
" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
Hi Luiz,
On Fri, Dec 2, 2016 at 3:56 AM, Luiz Augusto von Dentz
<[email protected]> wrote:
> Hi Petri,
>
> On Thu, Dec 1, 2016 at 11:12 PM, Petri Gynther <[email protected]> wrote:
>> However, in this case, I think this handling is correct.
>> load_gatt_db() showed "No cache for LEFQAU", so BlueZ has to
>> re-discover everything from the device over BLE.
>> But, since the device disconnected in the middle of discovery, BlueZ
>> couldn't fully populate the GATT DB and has to clean it.
>> If the device didn't disconnect so quickly, this would have most likely worked.
>>
>>> But I do agree that we should not reset the db if that was populated
>>> already, so I will try to fix that.
>>
>> Yes, once BlueZ does not reset the GATT DB on failed reconnects, this
>> problem will be solved.
>
> Please check if everything is alright when using upstream, it should
> clear the database anymore if we get an early disconnect.
I applied my 2 patches and your 2 patches on top of 5.43.
GATT DB is no longer destroyed on reconnection errors, so that's excellent.
However, we are still seeing reconnect problems, but not GATT DB related:
bluez: bluetoothd[17780]:
src/gatt-client.c:btd_gatt_client_connected() Device connected.
bluez: bluetoothd[17780]: profiles/gap/gas.c:read_device_name_cb()
Reading device name failed with ATT error: 0
bluez: bluetoothd[17780]: profiles/gap/gas.c:read_appearance_cb()
Reading appearance failed with ATT error: 0
bluez: bluetoothd[17780]: Error reading PNP_ID value: Unexpected error code
bluez: bluetoothd[17780]: BATT level_read_char_cb failed: Request
attribute has encountered an unlikely error
We are still investigating this. Likely a firmware issue on the remote.
>
>
> --
> Luiz Augusto von Dentz
Hi Petri,
On Thu, Dec 1, 2016 at 11:12 PM, Petri Gynther <[email protected]> wrote:
> However, in this case, I think this handling is correct.
> load_gatt_db() showed "No cache for LEFQAU", so BlueZ has to
> re-discover everything from the device over BLE.
> But, since the device disconnected in the middle of discovery, BlueZ
> couldn't fully populate the GATT DB and has to clean it.
> If the device didn't disconnect so quickly, this would have most likely worked.
>
>> But I do agree that we should not reset the db if that was populated
>> already, so I will try to fix that.
>
> Yes, once BlueZ does not reset the GATT DB on failed reconnects, this
> problem will be solved.
Please check if everything is alright when using upstream, it should
clear the database anymore if we get an early disconnect.
--
Luiz Augusto von Dentz
Hi Luiz,
On Thu, Dec 1, 2016 at 12:21 AM, Luiz Augusto von Dentz
<[email protected]> wrote:
> Hi Petri,
>
> On Thu, Dec 1, 2016 at 12:15 AM, Petri Gynther <[email protected]> wrote:
>> Hi Luiz,
>>
>> On Wed, Nov 30, 2016 at 1:37 AM, Luiz Augusto von Dentz
>> <[email protected]> wrote:
>>> Hi Petri,
>>>
>>> On Wed, Nov 30, 2016 at 10:36 AM, Luiz Augusto von Dentz
>>> <[email protected]> wrote:
>>>> Hi Petri,
>>>>>
>>>>> This primary services re-discovery on every reconnect is actually now
>>>>> causing a problem for us.
>>>>>
>>>>> Basically, this is what happens:
>>>>> 1. HoG remote control reconnects to BlueZ host for firmware update check.
>>>>> 2. BlueZ starts re-discovering the services of the remote, but doesn't
>>>>> yet complete it.
>>>>> 3. The remote disconnects after being connected for 2 seconds (no
>>>>> firmware update was available, so quickly disconnect to save battery).
>>>>> 4. BlueZ declares the HoG remote "bad" since it couldn't complete step
>>>>> (2). And then, BlueZ ends up removing the HoG remote services from its
>>>>> GATT database completely.
>>>>> 5. On the next reconnect attempt, the remote does not work. Re-pairing
>>>>> is required.
>>>>>
>>>>> Obviously, this is bad for user experience. Therefore, I'm asking:
>>>>> 1. Is there a way to avoid services re-discovery on every reconnect?
>>>>> 2. If the remote control is successfully bonded previously, and BlueZ
>>>>> experiences a problem during reconnect (services re-discovery), can we
>>>>> avoid destroying the bonding and GATT info on BlueZ side? A failed
>>>>> reconnect should not be a reason to remove a bonded device.
>>>>
>>>> The second point should definitely be fixed, but I wonder how the
>>>> firmware update check does actually detects if the host is not doing
>>>> something important before it decides it has to save power. Also if I
>>>> recall this correctly dfu was exactly why some devices needed the
>>>> database check, they boot in dfu mode which has a different database
>>>> but they completely lost the state of service changed subscriptions so
>>>> basically nothing works since all handles are invalid and even if
>>>> service changed would work it would cause a rediscover anyway.
>>>
>>> Checking the code I did not find anything that could have break the
>>> remote services, or perhaps it is the passive scanning/reconnection
>>> logic that gets broken if we failed to discover the services?
>>>
>> 11/12,060343.698 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
>> Primary service discovery failed. ATT ECODE: 0x00
>
> There is something wrong with your setup then, here it reconnect just fine:
>
> https://paste.fedoraproject.org/494521/58036114/
>
Thanks for sharing the above.
Here is the first reconnect attempt from our remote after the services
had been removed on previous failure:
11/12,061843.757 bluez: bluetoothd[3980]:
src/gatt-database.c:connect_cb() New incoming LE ATT connection
11/12,061843.757 bluez: bluetoothd[3980]:
src/device.c:device_attach_att() Elevating security level since LTK is
available
11/12,061843.780 bluez: bluetoothd[3980]:
attrib/gattrib.c:g_attrib_ref() 0x51c360: g_attrib_ref=1
11/12,061843.780 bluez: bluetoothd[3980]:
src/gatt-client.c:btd_gatt_client_connected() Device connected.
11/12,061843.780 bluez: bluetoothd[3980]: src/device.c:load_gatt_db()
Restoring LEFQAU gatt database from file
11/12,061843.783 bluez: bluetoothd[3980]: No cache for LEFQAU
11/12,061843.944 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
MTU exchange complete, with MTU: 23
11/12,061846.226 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Primary services found: 9
11/12,061846.226 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0001, end: 0x000b, uuid: 00001800-0000-1000-8000-00805f9b34fb
11/12,061846.227 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x000c, end: 0x000f, uuid: 00001801-0000-1000-8000-00805f9b34fb
11/12,061846.227 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0010, end: 0x0022, uuid: 0000180a-0000-1000-8000-00805f9b34fb
11/12,061846.230 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0023, end: 0x0028, uuid: 0000180f-0000-1000-8000-00805f9b34fb
11/12,061846.230 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0029, end: 0x002e, uuid: 00001813-0000-1000-8000-00805f9b34fb
11/12,061846.230 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x002f, end: 0x0037, uuid: 0000fff0-0000-1000-8000-00805f9b34fb
11/12,061846.230 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0038, end: 0x005c, uuid: 00001812-0000-1000-8000-00805f9b34fb
11/12,061846.230 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x005d, end: 0x0070, uuid: f000fef0-0451-4000-b000-000000000000
11/12,061846.232 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0071, end: 0xffff, uuid: f000ffc0-0451-4000-b000-000000000000
11/12,061846.757 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Secondary service discovery failed. ATT ECODE: 0x10
11/12,061847.497 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Included services found: 1
11/12,061847.497 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
handle: 0x0039, start: 0x0023, end: 0x0028,uuid:
0000180f-0000-1000-8000-0080
11/12,061847.644 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Characteristics found: 5
11/12,061847.644 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0002, end: 0x0003, value: 0x0003, props: 0x02, uuid:
00002a00-0000-1
11/12,061847.646 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0004, end: 0x0005, value: 0x0005, props: 0x02, uuid:
00002a01-0000-1
11/12,061847.646 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0006, end: 0x0007, value: 0x0007, props: 0x0a, uuid:
00002a02-0000-1
11/12,061847.648 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0008, end: 0x0009, value: 0x0009, props: 0x08, uuid:
00002a03-0000-1
11/12,061847.648 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x000a, end: 0x000b, value: 0x000b, props: 0x02, uuid:
00002a04-0000-1
11/12,061847.715 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Characteristics found: 1
11/12,061847.715 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x000d, end: 0x000f, value: 0x000e, props: 0x20, uuid:
00002a05-0000-1
11/12,061847.735 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Descriptors found: 1
11/12,061847.735 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
handle: 0x000f, uuid: 00002902-0000-1000-8000-00805f9b34fb
11/12,061847.871 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Characteristics found: 9
11/12,061847.871 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0011, end: 0x0012, value: 0x0012, props: 0x02, uuid:
00002a23-0000-1
11/12,061847.871 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0013, end: 0x0014, value: 0x0014, props: 0x02, uuid:
00002a24-0000-1
11/12,061847.874 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0015, end: 0x0016, value: 0x0016, props: 0x02, uuid:
00002a25-0000-1
11/12,061847.874 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0017, end: 0x0018, value: 0x0018, props: 0x02, uuid:
00002a26-0000-1
11/12,061847.878 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0019, end: 0x001a, value: 0x001a, props: 0x02, uuid:
00002a27-0000-1
11/12,061847.886 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x001b, end: 0x001c, value: 0x001c, props: 0x02, uuid:
00002a28-0000-1
11/12,061847.887 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x001d, end: 0x001e, value: 0x001e, props: 0x02, uuid:
00002a29-0000-1
11/12,061847.888 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x001f, end: 0x0020, value: 0x0020, props: 0x02, uuid:
00002a2a-0000-1
11/12,061847.890 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0021, end: 0x0022, value: 0x0022, props: 0x02, uuid:
00002a50-0000-1
11/12,061848.426 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Characteristics found: 1
11/12,061848.426 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
start: 0x0024, end: 0x0028, value: 0x0025, props: 0x12, uuid:
00002a19-0000-1
==== again here, early disconnect from remote side ====
11/12,061848.999 bluez: bluetoothd[3980]:
src/adapter.c:dev_disconnected() Device LEFQAU disconnected, reason 3
11/12,061848.999 bluez: bluetoothd[3980]:
src/adapter.c:dev_disconnected() device 0x522c18 paired 1 bonded 1
bonding 0
11/12,061848.999 bluez: bluetoothd[3980]:
src/adapter.c:adapter_remove_connection()
11/12,061848.999 bluez: bluetoothd[3980]:
plugins/policy.c:disconnect_cb() reason 3
11/12,061848.999 bluez: bluetoothd[3980]:
src/adapter.c:bonding_attempt_complete() hci0 bdaddr LEFQAU type 1
status 0xe
11/12,061849.000 bluez: bluetoothd[3980]:
src/device.c:device_bonding_complete() bonding (nil) status 0x0e
11/12,061849.000 bluez: bluetoothd[3980]:
src/device.c:device_bonding_failed() status 14
11/12,061849.001 bluez: bluetoothd[3980]: src/adapter.c:resume_discovery()
==== and again, since the re-discovery of services didn't complete
fully, GATT DB gets cleaned ====
11/12,061849.002 bluez: bluetoothd[3980]:
src/device.c:gatt_service_removed() start: 0x0001, end: 0x000b
11/12,061849.003 bluez: bluetoothd[3980]:
src/device.c:gatt_service_removed() start: 0x000c, end: 0x000f
11/12,061849.004 bluez: bluetoothd[3980]:
src/device.c:gatt_service_removed() start: 0x0010, end: 0x0022
11/12,061849.020 bluez: bluetoothd[3980]: src/device.c:gatt_debug()
Failed to initialize gatt-client
11/12,061849.021 bluez: bluetoothd[3980]:
src/device.c:gatt_client_ready_cb() status: failed, error: 0
11/12,061849.021 bluez: bluetoothd[3980]:
src/device.c:device_svc_resolved() /org/bluez/hci0/dev_LEFQAU err -5
11/12,061849.027 bluez: bluetoothd[3980]: src/device.c:att_disconnected_cb()
11/12,061849.032 bluez: bluetoothd[3980]:
src/device.c:att_disconnected_cb() Connection reset by peer (131)
11/12,061849.049 bluez: bluetoothd[3980]:
src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected.
Cleaning up.
11/12,061849.056 bluez: bluetoothd[3980]:
attrib/gattrib.c:g_attrib_unref() 0x51c360: g_attrib_unref=0
However, in this case, I think this handling is correct.
load_gatt_db() showed "No cache for LEFQAU", so BlueZ has to
re-discover everything from the device over BLE.
But, since the device disconnected in the middle of discovery, BlueZ
couldn't fully populate the GATT DB and has to clean it.
If the device didn't disconnect so quickly, this would have most likely worked.
> But I do agree that we should not reset the db if that was populated
> already, so I will try to fix that.
Yes, once BlueZ does not reset the GATT DB on failed reconnects, this
problem will be solved.