Get characteristic only work the first time
Reported by
acas...@gmail.com,
Jun 29 2016
|
|||||||||
Issue descriptionChrome Version : Chromium 53.0.2782.0 (Developer Build) (64-bit) Revision d63b5218dab7a9675f8de0842c0f3ac5febcb94f-refs/heads/master@{#402234} OS Linux Debian Sid kernel 4.6.0-1-amd64 and BlueZ 5.40 What steps will reproduce the problem? (1) Open https://googlechrome.github.io/samples/web-bluetooth/discover-services-and-characteristics.html (2) Put an UUID from a Service (I'm using the Nordic nRF51822 UART firmware the UUID is 6e400001-b5a3-f393-e0a9-e50e24dcca9e (3) It will return the characteristic correctly for the first test. (4) Close browser and try again and it fill fail What is the expected result? The listing of characteristics. What happens instead? > Name: Nordic_UART > Allowed Services: 6e400001-b5a3-f393-e0a9-e50e24dcca9e Connecting to GATT Server... Getting Services... Argh! NotFoundError: No Services found in device. Please find attached the log for the first time (working situation), I'm going to repeat the test to create the fail situation log.
,
Jun 29 2016
It looks like your device gets disconnected. Could you share btmon logs as well for the second time? $ sudo btmon
,
Jun 29 2016
Please find attached my btmon.log when the issue happen.
,
Jun 29 2016
Somehow your device triggers disconnection:
< HCI Command: Disconnect (0x01|0x0006) plen 3 [hci0] 24.264121
Handle: 71
Reason: Remote User Terminated Connection (0x13)
You might want to pair it first from bluetoothctl and see if that changes anything:
[bluetooth]# pair EC:F2:E5:CE:30:5B
If so, that means the pairing agent doesn't do its job properly.
,
Jun 29 2016
Pair is not working: [bluetooth]# pair EC:F2:E5:CE:30:5B Attempting to pair with EC:F2:E5:CE:30:5B [CHG] Device EC:F2:E5:CE:30:5B Connected: yes Failed to pair: org.bluez.Error.AuthenticationFailed [CHG] Device EC:F2:E5:CE:30:5B Connected: no
,
Jun 29 2016
This is the same get characteristic test using TI SensorTag device instead of Nordic UART board.
,
Jun 29 2016
Closing the TAB where the web bluetooth is loaded will disconnect the bluetooth, then opening a new TAB and trying to get characteristic will fail in the same way.
This is the log:
< HCI Command: LE Set Random Address (0x08|0x0005) plen 6 [hci0] 337.303019
Address: 25:21:A1:83:24:C4 (Non-Resolvable)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 337.304543
LE Set Random Address (0x08|0x0005) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 [hci0] 337.304561
Type: Active (0x01)
Interval: 22.500 msec (0x0024)
Window: 11.250 msec (0x0012)
Own address type: Random (0x01)
Filter policy: Accept all advertisement (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 337.305542
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 337.305554
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 337.306558
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: Inquiry (0x01|0x0001) plen 5 [hci0] 337.306578
Access code: 0x9e8b33 (General Inquiry)
Length: 10.24s (0x08)
Num responses: 0
> HCI Event: Command Status (0x0f) plen 4 [hci0] 337.321563
Inquiry (0x01|0x0001) ncmd 1
Status: Success (0x00)
@ Discovering: 0x01 (7)
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 337.383582
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 337.385581
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 337.605578
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 337.607578
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 337.644579
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 337.646581
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 337.954566
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 337.956548
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -24 dBm (0xe8)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -24 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 337.999564
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 338.001567
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 338.044577
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 338.046567
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 338.312610
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 338.314610
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 338.630572
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 338.632640
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 338.858626
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 338.860626
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -26 dBm (0xe6)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -26 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 338.902571
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 338.904605
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -25 dBm (0xe7)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -25 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 339.185534
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -26 dBm (0xe6)
> HCI Event: LE Meta Event (0x3e) plen 30 [hci0] 339.187559
LE Advertising Report (0x02)
Num reports: 1
Event type: Scan response - SCAN_RSP (0x04)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 18
128-bit Service UUIDs (complete): 1 entry
6e400001-b5a3-f393-e0a9-e50e24dcca9e
RSSI: -26 dBm (0xe6)
@ Device Found: EC:F2:E5:CE:30:5B (2) rssi -26 flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
11 07 9e ca dc 24 0e e5 a9 e0 93 f3 a3 b5 01 00 .....$..........
40 6e @n
< HCI Command: Inquiry Cancel (0x01|0x0002) plen 0 [hci0] 339.330876
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 339.338564
Inquiry Cancel (0x01|0x0002) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 339.338615
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 339.351561
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Parameters (0x08|0x000b) plen 7 [hci0] 339.351682
Type: Passive (0x00)
Interval: 60.000 msec (0x0060)
Window: 30.000 msec (0x0030)
Own address type: Public (0x00)
Filter policy: Ignore not in white list (0x01)
@ Discovering: 0x00 (7)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 339.355551
LE Set Scan Parameters (0x08|0x000b) ncmd 1
Status: Success (0x00)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 339.355583
Scanning: Enabled (0x01)
Filter duplicates: Enabled (0x01)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 339.359556
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 28 [hci0] 339.372567
LE Advertising Report (0x02)
Num reports: 1
Event type: Connectable undirected - ADV_IND (0x00)
Address type: Random (0x01)
Address: EC:F2:E5:CE:30:5B (Static)
Data length: 16
Name (complete): Nordic_UART
Flags: 0x05
LE Limited Discoverable Mode
BR/EDR Not Supported
RSSI: -25 dBm (0xe7)
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 [hci0] 339.372650
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 [hci0] 339.377551
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: LE Create Connection (0x08|0x000d) plen 25 [hci0] 339.377598
Scan interval: 60.000 msec (0x0060)
Scan window: 60.000 msec (0x0060)
Filter policy: White list is not used (0x00)
Peer address type: Random (0x01)
Peer address: EC:F2:E5:CE:30:5B (Static)
Own address type: Public (0x00)
Min connection interval: 50.00 msec (0x0028)
Max connection interval: 70.00 msec (0x0038)
Connection latency: 0x0000
Supervision timeout: 420 msec (0x002a)
Min connection length: 0.000 msec (0x0000)
Max connection length: 0.000 msec (0x0000)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 339.384526
LE Create Connection (0x08|0x000d) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 19 [hci0] 339.430560
LE Connection Complete (0x01)
Status: Success (0x00)
Handle: 71
Role: Master (0x00)
Peer address type: Random (0x01)
Peer address: EC:F2:E5:CE:30:5B (Static)
Connection interval: 70.00 msec (0x0038)
Connection latency: 0.00 msec (0x0000)
Supervision timeout: 420 msec (0x002a)
Master clock accuracy: 0x00
< HCI Command: LE Read Remote Used Fe.. (0x08|0x0016) plen 2 [hci0] 339.430734
Handle: 71
@ Device Connected: EC:F2:E5:CE:30:5B (2) flags 0x0000
0c 09 4e 6f 72 64 69 63 5f 55 41 52 54 02 01 05 ..Nordic_UART...
> HCI Event: Command Status (0x0f) plen 4 [hci0] 339.434558
LE Read Remote Used Features (0x08|0x0016) ncmd 1
Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 12 [hci0] 339.562558
LE Read Remote Used Features (0x04)
Status: Success (0x00)
Handle: 71
Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
LE Encryption
< ACL Data TX: Handle 71 flags 0x00 dlen 7 [hci0] 339.562784
ATT: Exchange MTU Request (0x02) len 2
Client RX MTU: 517
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 339.632565
Num handles: 1
Handle: 71
Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 7 [hci0] 339.708570
ATT: Exchange MTU Response (0x03) len 2
Server RX MTU: 23
< ACL Data TX: Handle 71 flags 0x00 dlen 11 [hci0] 339.708859
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0001-0xffff
Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 339.772565
Num handles: 1
Handle: 71
Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 18 [hci0] 339.842033
ATT: Read By Group Type Response (0x11) len 13
Attribute data length: 6
Attribute group list: 2 entries
Handle range: 0x0001-0x0007
UUID: Generic Access Profile (0x1800)
Handle range: 0x0008-0x0008
UUID: Generic Attribute Profile (0x1801)
< ACL Data TX: Handle 71 flags 0x00 dlen 11 [hci0] 339.842189
ATT: Read By Group Type Request (0x10) len 6
Handle range: 0x0009-0xffff
Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 339.912536
Num handles: 1
Handle: 71
Count: 1
> ACL Data RX: Handle 71 flags 0x02 dlen 26 [hci0] 339.982052
ATT: Read By Group Type Response (0x11) len 21
Attribute data length: 20
Attribute group list: 1 entry
Handle range: 0x0009-0xffff
UUID: Unknown (6e400001-b5a3-f393-e0a9-e50e24dcca9e)
,
Jun 30 2016
I guess this is not a failure to discover the attributes as it works the first time, it is probably the enumeration of already existing attributes that doesn't work for some reason. This used to work but perhaps something has changed recently, perhaps the code is now cleaning up the attributes on disconnect?
,
Jun 30 2016
OK. So to check if Chrome is culprit there, Alan please download chrome-linux.zip from http://commondatastorage.googleapis.com/chromium-browser-snapshots/index.html?prefix=Linux_x64/400610/ It it the same Chrome version I'm running now on my Chromebook which works fine. If you can reproduce the issue with this version, this means we'll have to check BlueZ.
,
Jun 30 2016
Ok, tested with Chromium version: 53.0.2773.0 (Developer Build) (64-bit) Tested page sample: https://beaufortfrancois.github.io/samples/web-bluetooth/characteristic-properties.html Same issue! First time (if BLE device address is not in the bluetoothctl cache) it is working fine: Requesting Bluetooth Device... Connecting to GATT Server... Getting Service... Getting Characteristic... > Characteristic UUID: 6e400002-b5a3-f393-e0a9-e50e24dcca9e > Broadcast: false > Read: false > Write w/o response: true > Write: true > Notify: false > Indicate: false > Signed Write: false > Queued Write: false > Writable Auxiliaries: false Second time it reports that the service doesn't exist: Requesting Bluetooth Device... Connecting to GATT Server... Getting Service... Argh! NotFoundError: No Services with specified UUID found in Device.
,
Jun 30 2016
Can you try something for me Alan? - Open chromium, - Go to https://beaufortfrancois.github.io/samples/web-bluetooth/characteristic-properties.html - Fill appropriate fields and click button (it should work fine) - Open bluetoothctl - Connect manually to the BLE device with "connect 12:34:56:78:90:12" - Close chromium - Reopen chromium - Go to https://beaufortfrancois.github.io/samples/web-bluetooth/characteristic-properties.html - Fill appropriate fields and click button What happens now?
,
Jun 30 2016
Please find the chrome logs for working and failing situations
,
Jun 30 2016
Initially Chromium is closed and device connection is in the cache Let us to remove it: [bluetooth]# remove EC:F2:E5:CE:30:5B [DEL] Primary Service /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0008 Generic Attribute Profile [DEL] Descriptor /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009/char000a/desc000c Client Characteristic Configuration [DEL] Characteristic /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009/char000a Vendor specific [DEL] Characteristic /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009/char000d Vendor specific [DEL] Primary Service /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009 Vendor specific [DEL] Device EC:F2:E5:CE:30:5B Nordic_UART Device has been removed Opened Chromium and executed a get characteristic: [CHG] Controller 00:1A:7D:DA:71:10 Discovering: yes [NEW] Device EC:F2:E5:CE:30:5B Nordic_UART [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI: -33 [CHG] Device EC:F2:E5:CE:30:5B RSSI is nil [CHG] Controller 00:1A:7D:DA:71:10 Discovering: no [CHG] Device EC:F2:E5:CE:30:5B Connected: yes [CHG] Device EC:F2:E5:CE:30:5B Trusted: yes [NEW] Primary Service /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0008 Generic Attribute Profile [NEW] Primary Service /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009 Vendor specific [NEW] Characteristic /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009/char000a Vendor specific [NEW] Descriptor /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009/char000a/desc000c Client Characteristic Configuration [NEW] Characteristic /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B/service0009/char000d Vendor specific [CHG] Device EC:F2:E5:CE:30:5B UUIDs: 00001800-0000-1000-8000-00805f9b34fb [CHG] Device EC:F2:E5:CE:30:5B UUIDs: 00001801-0000-1000-8000-00805f9b34fb [CHG] Device EC:F2:E5:CE:30:5B UUIDs: 6e400001-b5a3-f393-e0a9-e50e24dcca9e [CHG] Device EC:F2:E5:CE:30:5B ServicesResolved: yes [CHG] Device EC:F2:E5:CE:30:5B ServicesResolved: no Closed Chromium: [CHG] Device EC:F2:E5:CE:30:5B Connected: no Now force a connection from bluetoothctl side: [bluetooth]# connect EC:F2:E5:CE:30:5B Attempting to connect to EC:F2:E5:CE:30:5B [CHG] Device EC:F2:E5:CE:30:5B Connected: yes Connection successful Open chromium again and try to get characteristic (it will work second time because we connected from bluetoothctl) [CHG] Device EC:F2:E5:CE:30:5B ServicesResolved: yes [CHG] Controller 00:1A:7D:DA:71:10 Discovering: yes [CHG] Controller 00:1A:7D:DA:71:10 Discovering: no [CHG] Device EC:F2:E5:CE:30:5B ServicesResolved: no Chromium read it from cache propably. Closed chromium: [CHG] Device EC:F2:E5:CE:30:5B Connected: no [bluetooth]# Next time chomium don't get the characteristic: [CHG] Controller 00:1A:7D:DA:71:10 Discovering: yes [CHG] Controller 00:1A:7D:DA:71:10 Discovering: no [CHG] Device EC:F2:E5:CE:30:5B Connected: yes [CHG] Device EC:F2:E5:CE:30:5B ServicesResolved: yes I saw this error message in the chromium: Requesting Bluetooth Device... Connecting to GATT Server... Getting Service... Argh! NotFoundError: No Services with specified UUID found in Device.
,
Jun 30 2016
In chrome_working_debug.log, we get: [23153:23153:0630/095220:VERBOSE1:web_bluetooth_service_impl.cc(255)] Services discovered for device: EC:F2:E5:CE:30:5B [23153:23153:0630/095220:VERBOSE1:web_bluetooth_service_impl.cc(156)] Looking for service: 6e400001-b5a3-f393-e0a9-e50e24dcca9e [23153:23153:0630/095220:VERBOSE1:web_bluetooth_service_impl.cc(159)] Service in cache: 6e400001-b5a3-f393-e0a9-e50e24dcca9e [23153:23153:0630/095220:VERBOSE1:web_bluetooth_service_impl.cc(159)] Service in cache: 00001801-0000-1000-8000-00805f9b34fb [23153:23153:0630/095220:VERBOSE1:web_bluetooth_service_impl.cc(732)] Services found in device. [23153:23153:0630/095220:VERBOSE3:bluetooth_device_bluez.cc(572)] All services were discovered for device: /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B While in chrome_failing_debug.log, we get: [23576:23576:0630/095319:VERBOSE1:web_bluetooth_service_impl.cc(255)] Services discovered for device: EC:F2:E5:CE:30:5B [23576:23576:0630/095319:VERBOSE1:web_bluetooth_service_impl.cc(156)] Looking for service: 6e400001-b5a3-f393-e0a9-e50e24dcca9e [23576:23576:0630/095319:VERBOSE1:web_bluetooth_service_impl.cc(740)] Services not found in device. [23576:23576:0630/095319:VERBOSE3:bluetooth_device_bluez.cc(572)] All services were discovered for device: /org/bluez/hci0/dev_EC_F2_E5_CE_30_5B Does that mean BlueZ doesn't send us cached attributes? Are we failing to update Chromium Bluetooth services/characteristics cache
,
Jun 30 2016
Could you also share dbus messages when it's working and not working? sudo dbus-monitor --system "interface=org.freedesktop.DBus.Properties" "interface=org.freedesktop.DBus.ObjectManager"
,
Jun 30 2016
Please find attached 4 logs: 1º = worked - device is not in the cache (remove dev_addr) 2º = failed for unkwnon reason 3º = failed with normal error (NotFoundError: No Services with specified UUID found in Device.) 4º = worked after issue a connection from bluetoothctl
,
Jun 30 2016
After much discussion on #bluez-users IRC, we think https://chromium.googlesource.com/chromium/src/+/da9047813fef5c79e536420281860c62606e8201 could be introducing a regression. 15:41 <fbeaufort> Could https://chromium.googlesource.com/chromium/src/+/da9047813fef5c79e536420281860c62606e8201 be the one in Chromium failing us...? 15:49 <vudentz> + if (!IsGattServicesDiscoveryComplete()) { 15:49 <vudentz> + VLOG(2) << "Gatt services have not been fully resolved for device " 15:49 <vudentz> + << object_path_.value(); 15:49 <vudentz> + return; 15:49 <vudentz> + } 15:49 <vudentz> This is probably false if the device is disconnected since ServicesResolved: no in that case 15:50 <vudentz> This would explain why it is not enumerating the service on InitializeGattServiceMap 15:50 <vudentz> + // Notify on the discovery complete for each service which is found in the 15:50 <vudentz> + // first discovery. 15:50 <vudentz> + DCHECK(adapter()); 15:50 <vudentz> + for (const auto& iter : gatt_services_) 15:50 <vudentz> + adapter()->NotifyGattDiscoveryComplete(iter.second); 15:51 <vudentz> This was also not in the original patch, why would we notify on the InitializeGattServiceMap, there should be any client waiting for it
,
Jun 30 2016
I believe the code was written under the assumption that ObjectAdded would be called for cached services, which is not what happens. I'm currently refactoring the code to handle this scenario. We have a test for this but it also sends out a ObjectAdded event.
,
Jun 30 2016
Hello Luiz,
Can you help with commenting on the following reply? Thank you so much.
5:49 <vudentz> + if (!IsGattServicesDiscoveryComplete()) {
15:49 <vudentz> + VLOG(2) << "Gatt services have not been fully resolved for device "
15:49 <vudentz> + << object_path_.value();
15:49 <vudentz> + return;
15:49 <vudentz> + }
15:49 <vudentz> This is probably false if the device is disconnected since ServicesResolved: no in that case
15:50 <vudentz> This would explain why it is not enumerating the service on InitializeGattServiceMap
Indeed, when a device is created, it is unlikely that the device connected immediately, so ServicesResolved doesn't changed to true. This check will always return, so the following code can never be executed.
15:50 <vudentz> + // Notify on the discovery complete for each service which is found in the
15:50 <vudentz> + // first discovery.
15:50 <vudentz> + DCHECK(adapter());
15:50 <vudentz> + for (const auto& iter : gatt_services_)
15:50 <vudentz> + adapter()->NotifyGattDiscoveryComplete(iter.second);
15:51 <vudentz> This was also not in the original patch, why would we notify on the InitializeGattServiceMap, there should be any client waiting for it
Since the rest of InitializeGattServiceMap will not be executed, NotifyGattDiscoveryComplete() will never be invoked. This block should be removed.
Instead of putting the initialization of the gatt_services_ list, it can be placed in BluetoothDeviceBlueZ::DevicePropertyChanged(). Then we simply check whether the list is empty or not, if so, initialize the list with a query to GATT services and notify the service added with BluetoothDeviceBlueZ::GattServiceAdded().
In this way, the services discovered in the first connection will be notified via the same function.
In the original patch, the GATT services are retrieved in the constructor of BluetoothDeviceBlue, where ServicesResolved is not yet toggled to true. In https://chromium.googlesource.com/chromium/src/+/da9047813fef5c79e536420281860c62606e8201, the goal is to make sure the service is fully discovered before retrieving any services. Unless retrieving the list of services before the service is fully discovered is the excepted usage, we can keep the current approach and correct the above check. :)
,
Jun 30 2016
,
Jun 30 2016
For info, I can reproduce this issue on Chrome OS - 53.0.2773.0 (Official Build) dev (64-bit) - Go to https://googlechrome.github.io/samples/web-bluetooth/read-characteristic-value-changed.html - Make sure nearby BLE device advertises battery service - Click button - Battery Service / Battery Level gets discovered - Sign out from Chrome OS - Sign in - Go back to https://googlechrome.github.io/samples/web-bluetooth/read-characteristic-value-changed.html - Make sure same nearby BLE device advertises battery service - Click button Result: Requesting Bluetooth Device... Connecting to GATT Server... Getting Battery Service... Argh! NotFoundError: No Services with specified UUID found in Device.
,
Jul 1 2016
,
Jul 1 2016
Moving this nonessential bug to the next milestone. For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
Jul 4 2016
,
Jul 8 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/214ea3e270584ca53cebe4e3412bf7585fbd4807 commit 214ea3e270584ca53cebe4e3412bf7585fbd4807 Author: ortuno <ortuno@chromium.org> Date: Fri Jul 08 19:44:57 2016 bluetooth: Update the map of GATT services when services resolve Before we updated the map two times: 1. When constructing the device object *iff* the services had been resolved. 2. When a new service was added. This meant that if there was a cached service before services resolved, the service would never be added to the map. There are a couple of changes: 1. No longer add BluetoothDeviceBluez as an observer of BluetoothDeviceClient. This follows the previous pattern of exposing a function that BluetoothAdapterClient will use to update the device. 2. When services are resolved we add all previously unknown services. 3. Modified 2 tests and added two extra ones to test all the following cases: 1. Cached services exist and discovery hasn't completed. 2. Cached services exist and discovery has completed. 3. New service is exposed with no previous cached services. 4. New service is exposed with previous cached service. Case 1 should cover this bug. BUG= 624400 Review-Url: https://codereview.chromium.org/2105423003 Cr-Commit-Position: refs/heads/master@{#404468} [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/bluez/bluetooth_adapter_bluez.cc [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/bluez/bluetooth_device_bluez.cc [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/bluez/bluetooth_device_bluez.h [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/bluez/bluetooth_gatt_bluez_unittest.cc [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/dbus/fake_bluetooth_device_client.cc [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/dbus/fake_bluetooth_device_client.h [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/dbus/fake_bluetooth_gatt_service_client.cc [modify] https://crrev.com/214ea3e270584ca53cebe4e3412bf7585fbd4807/device/bluetooth/dbus/fake_bluetooth_gatt_service_client.h
,
Jul 8 2016
,
Sep 28 2016
|
|||||||||
►
Sign in to add a comment |
|||||||||
Comment 1 by acas...@gmail.com
, Jun 29 20165.7 KB
5.7 KB View Download
23.2 KB
23.2 KB View Download