bluetooth: Chooser takes too much time to show on a crowded environment |
|||||||||
Issue descriptionVersion: Chrome Dev 53.0.2782.9 OS: Android 7.0.0; Nexus 6 Build/NPD90G <- DP5 What steps will reproduce the problem? (1) Go to https://googlechrome.github.io/samples/web-bluetooth/device-information-characteristics.html (2) Make sure lots of BLE beacons are nearby (3) Click button What is the expected output? Bluetooth chooser should show up quickly. What do you see instead? Wait.. wait... here it is finally after 9 seconds ;) See annotated adb logs: // Click "Pair" button. --------- beginning of main 07-19 12:00:30.016 8424 8424 V PhoneWindow: addContentView does not support content transitions // Waiting... --------- beginning of system 07-19 12:00:33.346 849 862 I ProcessStatsService: Prepared write state in 16ms 07-19 12:00:33.447 849 861 I ProcessStatsService: Pruning old procstats: /data/system/procstats/state-2016-06-07-08-23-11.bin // Bluetooth chooser shows up after 9 seconds! 07-19 12:00:39.205 8424 8424 D BluetoothAdapter: STATE_ON 07-19 12:00:39.213 8589 8600 D BtGatt.GattService: registerClient() - UUID=41c99e16-32f6-45eb-b351-163309b901b7 07-19 12:00:39.215 8589 8608 D BtGatt.GattService: onClientRegistered() - UUID=41c99e16-32f6-45eb-b351-163309b901b7, clientIf=10 07-19 12:00:39.216 8424 8716 D BluetoothLeScanner: onClientRegistered() - status=0 clientIf=10 mClientIf=0 07-19 12:00:39.217 8589 8630 D BtGatt.GattService: start scan with filters 07-19 12:00:39.224 8589 8611 D BtGatt.ScanManager: handling starting scan 07-19 12:00:39.237 8589 8608 D BtGatt.GattService: onScanFilterEnableDisabled() - clientIf=10, status=0, action=1 07-19 12:00:39.237 8589 8608 D BtGatt.ScanManager: callback done for clientIf - 10 status - 0 07-19 12:00:39.238 8589 8611 D BtGatt.ScanManager: configureFilterParamter 500 10000 1 0 07-19 12:00:39.245 8589 8608 D BtGatt.GattService: onScanFilterParamsConfigured() - clientIf=10, status=0, action=0, availableSpace=15 07-19 12:00:39.247 8589 8608 D BtGatt.ScanManager: callback done for clientIf - 10 status - 0 07-19 12:00:39.250 8589 8611 D BtGatt.ScanManager: configureRegularScanParams() - queue=1 07-19 12:00:39.250 8589 8611 D BtGatt.ScanManager: configureRegularScanParams() - ScanSetting Scan mode=2 mLastConfiguredScanSetting=-2147483648 07-19 12:00:39.250 8589 8611 D BtGatt.ScanManager: configureRegularScanParams - scanInterval = 8000configureRegularScanParams - scanWindow = 8000 07-19 12:00:39.256 8589 8608 D BtGatt.GattService: onScanParamSetupCompleted : 0 07-19 12:00:39.294 8424 8424 I Choreographer: Skipped 557 frames! The application may be doing too much work on its main thread. 07-19 12:00:39.356 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 50:66:11:32:7C:10 null 07-19 12:00:39.393 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5A:4E:05:E8:11:38 null 07-19 12:00:39.395 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 6B:85:48:5F:B7:7F Nexus 5X 07-19 12:00:39.397 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5C:F3:70:77:74:39 Chromebox for Meetings 07-19 12:00:39.400 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5E:5F:DA:3E:38:27 null 07-19 12:00:39.404 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 CA:54:48:65:A6:45 null 07-19 12:00:39.429 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 57:0D:FA:14:83:0A null 07-19 12:00:39.434 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 79:6C:E6:93:33:A5 null 07-19 12:00:39.436 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 78:00:DF:EB:CC:E4 null 07-19 12:00:39.460 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 56:76:42:2D:15:35 null 07-19 12:00:39.519 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 CD:36:32:47:CA:1C EST 07-19 12:00:39.529 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5E:5F:DA:3E:38:27 null 07-19 12:00:39.542 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5C:F3:70:77:74:39 Chromebox for Meetings 07-19 12:00:39.548 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 FB:1F:30:C2:94:EA null 07-19 12:00:39.572 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 57:0D:FA:14:83:0A null 07-19 12:00:39.577 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 6B:85:48:5F:B7:7F Nexus 5X 07-19 12:00:39.612 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 79:6C:E6:93:33:A5 null 07-19 12:00:39.622 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 78:00:DF:EB:CC:E4 null 07-19 12:00:39.714 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5E:5F:DA:3E:38:27 null 07-19 12:00:39.815 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 57:0D:FA:14:83:0A null 07-19 12:00:39.823 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 79:6C:E6:93:33:A5 null 07-19 12:00:39.832 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 78:00:DF:EB:CC:E4 null 07-19 12:00:39.896 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5E:5F:DA:3E:38:27 null 07-19 12:00:39.936 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 57:0D:FA:14:83:0A null 07-19 12:00:39.980 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 79:6C:E6:93:33:A5 null 07-19 12:00:39.993 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 78:00:DF:EB:CC:E4 null 07-19 12:00:40.054 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 FB:1F:30:C2:94:EA null 07-19 12:00:40.078 8424 8424 V cr_Bluetooth: [ChromeBluetoothAdapter.java:241] onScanResult 1 5E:5F:DA:3E:38:27 null ...
,
Jul 19 2016
Even having 100 devices in the UI, we should be able to display it rapidly. This is polish, but a real issue.
,
Jul 19 2016
That trace looks like the scan results don't even show up until after the 9-second delay. That would imply that the delay isn't about adding the results to the dialog.
,
Jul 19 2016
My guess is that the delay is happening when adding cached devices, but I could be wrong.
,
Jul 20 2016
I wonder if it's because of the logic we added for calculating the chooser's height. https://cs.chromium.org/chromium/src/chrome/android/java/src/org/chromium/chrome/browser/ItemChooserDialog.java?dr=CSs&sq=package:chromium&l=372
,
Jul 20 2016
Did you get the right bug for comment #5? I don't see anything in the height-computing code that depends on the number of devices.
,
Jul 20 2016
Ah sorry. I didn't look at the code close enough. You are right.
,
Aug 12 2016
,
Sep 7 2016
,
Sep 7 2016
,
Sep 7 2016
,
Sep 8 2016
,
Sep 8 2016
The chooser was not designed for so many devices being added and updated so quickly. So the fix would be to refactor ItemChooserDialog which will require some time. Ideally websites are using good filters and not many devices will show up so I'm not sure this is really that high in the list of priorities. WDYT?
,
Sep 8 2016
I'm not convinced that the linear searches in the chooser would add up to a multi-second delay even for 100 devices. I agree it's not high priority, but I also think it's something other than the chooser code causing the delay.
,
Sep 8 2016
I don't think it's the linear searches. It's the fact that we are calling notifyDataSetChanged (and thus redrawing the list) ~25 times in less than a second. I don't think ListView was originally intended for lists that are updating so fast. A better fit would be RecyclerView[1] [1] https://developer.android.com/reference/android/support/v7/widget/RecyclerView.html
,
Sep 9 2016
FWIW, I've just tried the newest Chromium build (55.0.2856.0) with a Nexus 5 phone (Android 5.1), Android One phone (Android 6.0), and Nexus 5X phone (Android 7.0) and as you can see in the picture, it ONLY happens with Android 7 Nougat.
,
Sep 27 2016
Sooo I narrowed down the problem to the BluetoothDevice.getName() function. I couldn't get instrumentation working on my device but all the jank goes away if we comment out the call to getName()[1] I have a WIP patch[2] but I would like a resolution on https://github.com/WebBluetoothCG/web-bluetooth/issues/299 first. [1] https://cs.chromium.org/chromium/src/device/bluetooth/android/java/src/org/chromium/device/bluetooth/ChromeBluetoothDevice.java?sq=package:chromium&l=92&dr=CSs [2] https://codereview.chromium.org/2377513004
,
Sep 27 2016
Good find.Just noticed the same in Opera. Tested a bit with getDeviceName() from ScanRecord and sometimes the name can be null and sometimes the real device name (last name is from the scan record): [ChromeBluetoothAdapter.java:244] onScanResult 1 D1:6E:07:45:B2:36 "Candy Dispenser" "Candy Dispenser" [ChromeBluetoothAdapter.java:244] onScanResult 1 D1:6E:07:45:B2:36 "Candy Dispenser" "null" (same pattern repeats) The chooser should probably not update the name if it gets null for device name as it might lead to a device being repeatedly added and removed while scanning.
,
Sep 28 2016
#20 right. That's the purpose of the should_update_name argument of BluetoothChooser::AddOrUpdateDevice[1]. [1] https://cs.chromium.org/chromium/src/content/public/browser/bluetooth_chooser.h?q=bluetooth_chooser&sq=package:chromium&dr=CSs&l=80
,
Oct 17 2016
,
Nov 15 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/f6c78e7050d893ffb0ccb150efa8d21703593a95 commit f6c78e7050d893ffb0ccb150efa8d21703593a95 Author: ortuno <ortuno@chromium.org> Date: Tue Nov 15 00:43:52 2016 bluetooth: Cache device name and uuids when iterating over filters Changes MatchesFilters to take the device's name and its uuids directly rather than taking a device and getting the name and uuids when iterating over the filters. This avoid calling BluetoothDevice::GetName() for every filter which caused lag on android when the request had too many filters. BUG= 629456 Review-Url: https://codereview.chromium.org/2496833002 Cr-Commit-Position: refs/heads/master@{#432026} [modify] https://crrev.com/f6c78e7050d893ffb0ccb150efa8d21703593a95/content/browser/bluetooth/bluetooth_device_chooser_controller.cc
,
Nov 15 2016
,
Nov 15 2016
Verified in Chromium build 56.0.2921.0 for Android. Thank you so much Giovanni! This is perfect now. |
|||||||||
►
Sign in to add a comment |
|||||||||
Comment 1 by ortuno@chromium.org
, Jul 19 2016Owner: ----