[WebBluetoothDemo.js] UI stops updating the temperature changes

[poussa]

After a while, maybe after 10 mins, the UI does not update the temperature changes any more. I see from the console that the changes are being recorded

Temperature change: 20.431640624999993 degrees Celsius

But the UI still show "24 C".

I also disconnected and reconnected but the issue remains. The LED control works fine.

[poussa]

@grgustaf @jimmy-huang @kenchris PTAL

[miaobin]

I tried to recurrent the issue this morning in commit ec608616b450e008d4d580e1ca4c9e9d0d52349c. But the sample works fine after running 30 minutes.

[jimmy-huang]

Maybe this is a Android issue? Maybe report the Android version and Chromium browser version installed ?

[haoxli]

Tested ~20 minutes on Nexus 5(Android 5.0) with Chromium 55.0.2846.0, not meet the UI stop updating issue. The UI is updating the same temperature as the console's. See the screenshot:

[poussa]

I only saw this once. On the UI it is stuck to a step: "Requesting Temperature characteristics...".

I am on Nexus 5 / Android 6.0.1 (Aug 5, 2016), Chrome 51.0.270.81

Other than this one incident it has been working OK including 48 hours in row.

[miaobin]

I tried WebBluetoothDemo.js and WebBluetooth GroveLcdDemo.js via physical web and reproduced this issue. I connected my Nexus 5 to Arduino 101. After 15 mins the UI does not update the temperature changes any more, but the LED/LCD control works fine.

[jimmy-huang]

So I just ran into a similar issue that's much more easily produced, after I updated to the latest Android 7.0 nougat on the Nexus 5X. If you click disconnect from the webpage, and then re-connect again to the same device, temperature update will no longer work, you can still change the LED. I've verified that on the Arduino side, we are still sending the updates over BLE, and if you refresh the page and reconnect, it will work again, so the problem is not on Zephyr or Arduino, I think there's a bug in either the web code or more likely, a Chromium browser bug that the update stops working after a disconnect. This was working fine on Android 6.0 Marshmallow. @grgustaf also sees this issue on his phone running 7.0 @kenchris ?

[grgustaf]

We are nearly certain that this problem lies in the Chrome WebBluetooth stack. If you test with the native Android app "nRF Connect" and connect to the device, you can open the "Unknown Service" and then click the three-arrows icon to start receiving notifications. They will seemingly go on indefinitely, and they work even when the web app can't receive them.

So it sure appears the device is behaving correctly, and Android BT driver is behaving correctly, it's something above that, namely the Chrome WebBluetooth support.

[kenchris]

Could you file a bug at crbug.com/new then?

[jimmy-huang]

@kenchris @grgustaf @poussa this might be the same bug, should I file a new bug or comment on this one?

https://bugs.chromium.org/p/chromium/issues/detail?id=647673

[kenchris]

If you believe it is the same, just comment and provide as much info as you can. Also star it to get updates

[poussa]

Including link to this issue.

[jimmy-huang]

Sounds good, I'll do that.

[beaufortfrancois]

Here are my findings: https://bugs.chromium.org/p/chromium/issues/detail?id=659443#c1

[kenchris]

Jimmy, I am not sure the above findings are correct as I retried service and charcs always when I connect. Francois asked for a bluetooth trace and referred to these links:

https://www.chromium.org/developers/how-tos/file-web-bluetooth-bugs https://medium.com/@urish/reverse-engineering-a-bluetooth-lightbulb-56580fcb7546#.vxm4hzbuv

[jimmy-huang]

@kenchris I'll see if I can reproduce so i can have a trace

[haoxli]

QA can reproduce it on both demo branch(commit 01be569) and devel branch(commit 21f0a17).

After 10-20mins, temperature stop updating in the Chromium UI, but continue updating in the console and Grove LCD.

• Start logging logcat output by:

adb logcat -v time | grep -E " 
|[Bb]luetooth|cr.Bluetooth|BtGatt|BluetoothGatt|bt_btif_config" > 
|logcat.txt

• When temperature update stopped in the UI, but in the console still seeing temperature update printed, then upload the trace and the hci log, get it by:

adb pull /sdcard/btsnoop_hci.log

Device Info: Chromium version: 55.0.2846.0 Device: Nexus 5(Android 5.0.1)

Because github does not support upload btsnoop_hci.log, so put the two log files in zip attachment, please take a look at them: demo_log.zip devel_log.zip

[beaufortfrancois]

Looking at ADB logs, I can see BLE notifications ongoing:

> ACL Data RX: Handle 64 flags 0x02 dlen 8           2016-10-28 09:17:48.296433
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x0003
          Data: 12
> ACL Data RX: Handle 64 flags 0x02 dlen 8           2016-10-28 09:17:49.808061
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x0003
          Data: 12
> ACL Data RX: Handle 64 flags 0x02 dlen 8           2016-10-28 09:17:50.295320
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x0003
          Data: 12
> ACL Data RX: Handle 64 flags 0x02 dlen 8           2016-10-28 09:17:50.782758
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x0003
          Data: 12
> ACL Data RX: Handle 64 flags 0x02 dlen 8           2016-10-28 09:17:51.269810
      ATT: Handle Value Notification (0x1b) len 3
        Handle: 0x0003
          Data: 13
...

while Chromium stops receiving those (timezone corrected for easier reading):

10-28 09:17:48.300 I/cr_Bluetooth( 4974): wrapper onCharacteristicChanged.
10-28 09:17:48.300 I/cr_Bluetooth( 4974): device onCharacteristicChanged.
10-28 09:17:48.305 I/cr_Bluetooth( 4974): onCharacteristicChanged

My guess here is that the JavaScript temperatureCharacteristic object gets garbage collected at some point (after 8 minutes to be exact) . What do you think @g-ortuno?

@haoxli Can you reproduce as well on a different platform? macOS, Chrome OS?

[g-ortuno]

I doubt that's the case. As long as temparatureCharacteristic has an event listener the object will not get garbage collected. Even then, we would see a disconnection but we continue to receive events.

Hmm I haven't been able to reproduce because I think there is a bug in the website: On line 392 of main-app.html we have this code:

 return this.fetchColorLEDCharc(service)
  .then(this.fetchTemperatureCharc(service));

Because this.fetchTemperatureCharc(service) is not in a function, the code is basically running fetchColorLEDCharc and fetchTemperatureCharc in parallel which means there are two concurrent calls to readValue. In my attempts to reproduce I haven't been able to subscribe to notifications because the second call fails.

Similarly on line 370 we have:

return this.readTemperature().then(
  this.temperatureCharacteristic.startNotifications()
);

Which means there are two concurrent calls to GATT operations again. It's possible the second call is failing so notifications are never started. You do get one notification because readValue() triggers a characteristicvaluechanged event.

Let me know if that fixes the problems.

[haoxli]

@beaufortfrancois I tried it on Chrome OS, but fail to connect with Arduino 101, it cannot find the device. @jimmy-huang do you know how to run this samples with Chrome OS or Mac OS?

[kenchris]

You are right,

function one() { return new Promise(resolve => { setTimeout(_ => {console.log("one"); resolve()}, 1000); })}
function two() { return new Promise(resolve => { setTimeout(_ => {console.log("two"); resolve()}, 500); })}

one().then(two())
Promise {[[PromiseStatus]]: "pending", [[PromiseValue]]: undefined}
VM440:1 two
VM401:1 one

one().then(two)
Promise {[[PromiseStatus]]: "pending", [[PromiseValue]]: undefined}
VM401:1 one
VM440:1 two

but that is a recent mistake since I added the service argument. It used to be

let p1 = one;
undefined
let p2 = two;
undefined
p1().then(p2)

Let me fix that.

[kenchris]

Problem is that I added the service argument... async/await will make this much easier

Will solve it this way:

function draft(arg, timeout) {
  return new Promise(resolve => { 
    setTimeout(_ => { console.log(arg); resolve() }, timeout);
  })
}

let one = draft.bind(this, "one", 1000);
let two = draft.bind(this, "two", 500);

one().then(two)

[kenchris]

OK, I pushed the change, please try. (sorry didn't do proper SW upgrade, so flush caches et al)

[jimmy-huang]

@haoxli we have not tried running it with ChromeOS since we don't have the hardware, but we've tried with Mac, and the on the mac, we had trouble discovering the BLE device, so we thought it was not supported yet but only on mobile devices.

[jimmy-huang]

@haoxli ok, so you can run it on Mac as well, have to enable web bluetooth flag in chrome://flags, also I had to update the arc/src/main.c and change the UPDATE_INTERVAL to 100, in order to connect to it. But I can't reproduce it on the Mac, it's been running for me all morning for couple hours. This is Chromium version 54.0.2840.71.

[g-ortuno]

@jimmy-huang were you able to reproduce on Android with the latest changes to the website? I haven't been able to reproduce on android since the changes.

[kenchris]

@g-ortuno I was never able to reproduce it, but I don't see how that change could affect the result after 8 minutes. Maybe I am missing something, but maybe you could enlighten me how :) Would be useful if we run into things like this again

[g-ortuno]

Ah sorry, I think I got confused with a similar issue that was reported at a similar time. I'll try to reproduce the issue after a couple of minutes.

[jimmy-huang]

@g-ortuno I am not able to reproduce anything here after I moved my cubes, but our QA team was still able to reproduce this last week, and then yesterday suddenly they can't reproduce it either.

[g-ortuno]

Strange... Anyway, thanks for the detailed report and feel free to open a new issue if you run into any problems again.

[jimmy-huang]

@haoxli please re-test again to see if you can still reproduce.

[haoxli]

Still not reproduce this issue on: Mac OS: 10.11.5 Chromium: 54.0.2840.87

Android: Nexus5(5.0.1) Chromium: 55.0.2846.0

Maybe we can close the issue, although not sure what happened to fix it, and re-open if it's reproduced again.

[grgustaf]

Sounds good, closing.