getPrimaryService() not resolving appropriately
Reported by
nallre...@gmail.com,
May 8 2017
|
||||
Issue descriptionChrome Version : 58.0.3029.96 (64-bit) What steps will reproduce the problem? (1) Make the initial connection to the device (2) Once the connection is completely finished refresh the page. (I've started notifications and setup listeners, the device is ready to use at this point) (3) Immediately try to connect to the device again. (4) This connection may succeed or may hang. If it hangs, keep trying until it hangs. (5) Once it hangs, the device must be powered off and powered back on. What is the expected result? The promise returned from getPrimaryService() should reject immediately and not require the device to be powered off and powered back on and the connection tried again. What happens instead? When the connection hangs, it is because the promise returned from getPrimaryService() does not resolve. At this point I disconnect the device and try to connect again. When I call device.gatt.connect() the hung promise from getPrimaryService() then resolves with error "NetworkError: GATT Server is disconnected. Cannot retrieve services. (Re)connect first with device.gatt.connect.". After that promise resolves, the promise returned from the most recent call to device.gatt.connect() resolves with error "GATT Server disconnected while retrieving characteristics.". At this point, I attempt to connect again and the connection appears to always be successful. Please provide any additional information below. Attach a screenshot if possible. I've made a note in the chrome logs where I powered off my device and powered it back on. I've also written a description of this bug here https://github.com/WebBluetoothCG/web-bluetooth/issues/367 These particular logs took my several tries to reproduce the bug, but the bug often occurs after only one refresh of the page. My platform is a macbook pro. I attempted to collect system logs, but when using BluetoothExplorer and the PacketLogger my device did not respond to commands. I was also unable to reproduce the bug with BluetoothExplorer and PacketLogger running.
,
May 8 2017
Yes please! Also when getPrimaryServices() resolves (when it resolves).
,
May 8 2017
"Unable to connect: NetworkError: GATT Server is disconnected. Cannot retrieve services. (Re)connect first with `device.gatt.connect`." Is the error when getPrimaryServices() resolves. "NetworkError: GATT Server disconnected while retrieving characteristics." is the error when device.gatt.connect resolves after I power off/on my device. Look at the logs immediately after the "ERROR!!!!" log. The logs following the "callback" log are just logging the same thing.
,
May 8 2017
In these logs I uploaded I refreshed once and had the issue. Then it is followed by a successful connection.
,
May 8 2017
Its also worth noting, my connection process involves making two calls to getPrimaryServices(). That is why you see it being called twice at the start of the logs and also twice at the end.
,
May 8 2017
Thanks for the logs! Hmm seems like a problem we've fixed in the past. Could you try reproducing your issue with Chrome Canary? We've added more logging statements and fixed bugs around that area in the past couple of weeks so the problem might be already be fixed. Chrome Canary: https://www.google.com/chrome/browser/canary.html
,
May 8 2017
I've tested with Canary earlier today and got the same results. I'm having trouble starting logs for Canary though... Tried this: /Applications/Google\ Chrome\ Canary.app/Contents/MacOS/Google\ Chrome --enable-logging=stderr --vmodule=*bluetooth*=2 I get: "No such file or directory", even though canary is in my applications directory. Is there another command for this?
,
May 8 2017
Also, I haven't been able to confirm, but I think this issue causes chrome to crash when I close my laptop and leave it for awhile. This happens fairly frequently when I'm working with bluetooth but I haven't yet confirmed it is only when this issue comes up. I'll keep an eye on that for the future.
,
May 8 2017
It's: /Applications/Google\ Chrome\ Canary.app/Contents/MacOS/Google\ Chrome\ Canary --enable-logging=stderr --vmodule=*bluetooth*=2 Note the "\ Canary" before "enable-logging". If you experience a crash you can go to: about:crashes and click on provide more information which will open an issue here.
,
May 8 2017
Thanks. I'll be sure to report the crash next time. Here are my logs from Canary. 60.0.3091.0
,
May 8 2017
+jlebel in case he has any ideas. The cause of the problem might be at a lower layer. From the logs I see that we stopped getting responses for descriptors after discovering the descriptors for the characteristic with UUID 9a66fa00-0800-9191-11e4-012d1540cb8e. We never receive the next response for characteristic with UUID 9a66fa0b-0800-9191-11e4-012d1540cb8e. I'll take a look at the errors we are returning tomorrow.
,
May 8 2017
Do you by any chance call gatt.disconnect() when the getPrimaryServices() promise rejects after disconnecting and reconnecting? I see that we start disconnecting right after the promise rejects at [5205:1547:0507/235638.967697:VERBOSE1:bluetooth_adapter_mac.mm(661)] <BluetoothLowEnergyDeviceMac A1:FC:B8:1F:7F:06/0x7f7fe9d082e0, GATT connected, "Mambo_288329">: Disconnect gatt. Seems like the connection succeeded, then getPrimaryServices() succeeded and then since you called disconnect() the getCharacteristics() call failed. The promise rejecting after reconnecting is because when you call getPrimaryServices() we queue a task to be run after Services are discovered, which only happens after reconnecting. That's a bug on our side.
,
May 9 2017
Yes, you are correct. I have a catch that is calling my cleanup method and the cleanup method always calls gatt.disconnect() on the device if it has a device available. Sorry about that. I'd been trying strange things in my code trying to get a work around for needing to restart my device.
,
May 9 2017
Ok! That gets rid of some of the weird errors. So we have two problems: 1. Discovery doesn't complete. 2. getPrimaryServices() calls are dispatched after a device reconnects. I'm still investigating 1. You mentioned that you were "unable to reproduce the bug with BluetoothExplorer and PacketLogger running." Did you try reproducing the bug with Chrome and PacketLogger running? Those logs would be useful to see if the problem is at a lower layer. Also if possible could you provide more information about the device you are using? I might be able to get my hands on one or try to replicate its characteristics. I've been trying to reproduce the bug with some of our devices but I have been unable to do so.
,
May 9 2017
When I ran with the BluetoothExplorer and PacketLogger running my device didn't respond when I sent it commands. I only tried a few times but I can give it another go. I'm using a Parrot Mambo mini drone.
,
May 9 2017
Running PacketLogger in the background and reproducing the issue with Chrome Canary should be enough. No need to run Bluetooth Explorer.
,
May 9 2017
I've attached chrome logs and packet logs. Let me know if those packet logs are what you're after. Chrome version is Version 60.0.3094.0 (Official Build) canary (64-bit)
,
May 9 2017
In these logs it took me two attempts to reproduce the bug.
,
May 9 2017
Would the following work to get around the problem?
function retrieveServicesForBuggyDevices(device) {
return Promise.race([
device.gatt.getPrimaryServices(),
new Promise(resolve => setTimeout(resolve, GET_PRIMARY_SERVICES_TIMEOUT))
])
.then(services => {
if (services === undefined) {
console.log('getPrimaryServices is taking too long.');
device.gatt.disconnect();
// wait for disconnection and try connecting again.
return new Promise(resolve => setTimeout(resolve, 1000))
.then(() => device.gatt.connect())
.then(() => retrieveServicesForBuggyDevices(device))
}
return services;
});
}
navigator.bluetooth.requestDevice(...)
.then(device => device.gatt.connect())
.then(gatt => retrieveServicesForBuggyDevices(gatt.device))
.then(services => ...);
,
May 9 2017
Unfortunately, that won't work either. I gave it a try to verify. Once the device is in this state it seems like the only option is to restart the device. I've tried calling device.gatt.disconnect() and reconnecting. Calling disconnect and refreshing the page doesn't make it resolve either. Once the device reaches that state, I haven't been able to get any gatt promises to resolve until I restart the device. For example, if I try multiple times to call device.gatt.connect() all attempts will hang. Then, when I restart my device and try to connect all of my promises resolve. It seems that the best I can do while this is still an issue is recognize that it has occurred and let the user know they need to restart their device. Your code here with Promise.race is more elegant than what I was doing.
,
May 9 2017
hmm there might be a bug in there as well. I'll update once I get my hands on a device.
,
May 10 2017
A bug in the device?
,
May 10 2017
Hard to say at this point i.e. might be an apple bug or a chrome bug as well.
,
May 10 2017
I'll try to reproduce this on an android device tomorrow.
,
May 10 2017
Can you reproduce with https://webdro.ne? I got a Rolling Spider device I can try if that might help.
,
May 10 2017
Chrome Canary 60.0.3095.0 MacBook Air (13-inch, Early 2015) Mac OS X (10.12.4) Device: Parrot Rolling Spider 1) Go to https://googlechrome.github.io/samples/web-bluetooth/discover-services-and-characteristics-async-await.html?optionalServices=9a66fa00-0800-9191-11e4-012d1540cb8e 2) Press "Discover services & characteristics" button 3) Notice device gets connected and that service's characteristics are discovered 4) Refresh web page 5) Repeat Step #2 to #4 several times. After 9 tries, I wasn't able to reproduce sadly ;( nallred91@, may you try to reproduce with these steps?
,
May 10 2017
Your link to https://webdro.ne doesn't take me anywhere. I will try to reproduce with a rolling spider in a few hours though. Using the connection utility link you sent me I can also not reproduce. The difference between that connection utility and my code is that I am also making a few calls to characteristic.startNotifications() and two calls to characteristic.addEventListener('characteristicvaluechanged', ...)
,
May 10 2017
Argh! I meant https://webdr.one not https://webdro.ne. It comes from https://github.com/poshaughnessy/web-bluetooth-parrot-drone Please let me know what is the outcome with the Rolling Spider.
,
May 10 2017
Ah yea, I've seen that before. webdr.one is buggy in general for me... I get errors right away on the initial connection. I've created a repo you can check out that simply allows you to connect and then begins pinging the drone. I thought it'd be helpful to just pull some of the relevant connection code out of my project. https://github.com/NAllred91/ParrotConnectionText I thought we had a rolling spider in the office but all we have at the moment is a Mambo and Mars. But I was able to reproduce the issue on both the Mambo and Mars, so this doesn't seem to be limited to just my specific Mambo. Can you try to reproduce using the repo I created? If you open the console I'm logging all the steps as I go through them. Once you see 'Pinging began' your drone is connected.
,
May 10 2017
I've used your code with my Rolling Spider and was able to get primary services 9 times in a row without any issue. Do I need a special version of the firmware?
,
May 10 2017
I don't believe so. I updated my firmware this morning and it hasn't made any difference. Also, when I refresh the page if I wait about 3-5 seconds before trying to connect again I can keep going through this process without issue as well. The hang only appears to happen when I refresh and the immediately start reconnecting.
,
May 10 2017
It also hangs if I press the disconnect button and then immediately press the connect button and try to connect again.
,
May 10 2017
@ortuno Your code snippet did help me. Instead of `calling disconnect() -> connect() -> getPrimaryService()` I tried just calling `connect() -> getPrimaryService()` again. When I do this after it times out, without trying to disconnect and reconnect, it is successful. This work around appears to make my user experience acceptable.
,
May 11 2017
For the record, my Rolling Spider info are: Product Type: Classic Hardware Version: HW_05 Software Version: 1.99.2 I also tried several times pressing the disconnect button and then immediately press the connect button and it worked perfectly fine for me. What are your results on Android?
,
May 11 2017
I tested on Android 6.0.1, Chrome 58.0.3029.83 When I refresh and quickly reconnect I get error "No Services matching UUID 9a66fa00-0800-9191-11e4-012d1540cb8e found in Device." Then, if I try to connect again it connects successfully.
,
May 11 2017
Also, my Mambo info: Product Type: Mambo Hardware Version: HW_02 Software Version: 2.6.6
,
May 20 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/8688a0dbe08b343fb8f0b736a506f79953e658e2 commit 8688a0dbe08b343fb8f0b736a506f79953e658e2 Author: Giovanni Ortuño Urquidi <ortuno@chromium.org> Date: Sat May 20 09:34:29 2017 bluetooth: Reject pending getPrimaryService(s) calls when the device disconnects This was causing getPrimaryService(s) promises to reject. Bug: 719289 Change-Id: I0860e53778cb6c8d1d69564bcbdd5438052769e8 Reviewed-on: https://chromium-review.googlesource.com/510055 Commit-Queue: Giovanni Ortuño Urquidi <ortuno@chromium.org> Reviewed-by: Vincent Scheib <scheib@chromium.org> Cr-Commit-Position: refs/heads/master@{#473430} [modify] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/content/browser/bluetooth/bluetooth_metrics.h [modify] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/content/browser/bluetooth/web_bluetooth_service_impl.cc [modify] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/content/browser/bluetooth/web_bluetooth_service_impl.h [modify] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/content/shell/browser/layout_test/layout_test_bluetooth_adapter_provider.cc [add] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/third_party/WebKit/LayoutTests/bluetooth/script-tests/server/device-disconnects-during.js [add] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/third_party/WebKit/LayoutTests/bluetooth/server/getPrimaryService/gen-device-disconnects-during.html [add] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/third_party/WebKit/LayoutTests/bluetooth/server/getPrimaryServices/gen-device-disconnects-during-with-uuid.html [add] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/third_party/WebKit/LayoutTests/bluetooth/server/getPrimaryServices/gen-device-disconnects-during.html [modify] https://crrev.com/8688a0dbe08b343fb8f0b736a506f79953e658e2/tools/metrics/histograms/enums.xml
,
May 22 2017
Could you try this again with the latest Canary?
,
May 22 2017
Using 60.0.3107.0. The promise returned from getPrimaryService() does not seem to hang any more. When I refresh the page and try to connect immediately, it immediately resolves with the error 'GATT Server is disconnected. Cannot retrieve services. (Re)connect first with `device.gatt.connect`' with error code 19. While doing the testing my browser was crashing a lot though, Crash Report ID's 1e89ec7d70000000 and e81e9c7d70000000 both occurred while testing this.
,
May 22 2017
Great! I tested it with a Mambo and it seems the mambo disconnects after reconnecting so there might be an issue in the mambo's software. Let me know if you see any other promises hanging. Thanks for the crash Ids. They seem to be the same issue you reported earlier i.e. chrome crashes when closing the laptop. I'm currently working on a fix.
,
May 23 2017
,
May 23 2017
fyi you can follow the progress on the other bug in Issue 724300 . |
||||
►
Sign in to add a comment |
||||
Comment 1 by nallre...@gmail.com
, May 8 2017