Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

'characteristicvaluechanged' callback doesn't seem to work #6

Open
PofNClimb opened this issue Mar 20, 2018 · 15 comments

Comments

Projects
None yet
4 participants
@PofNClimb
Copy link

commented Mar 20, 2018

Once notifications are enabled, and a 'characteristicvaluechanged' callback has been set, it doesn't seem to be triggered. This issue has been noted with this application that works perfectly with Google Chrome on Android and Windows 10 (with this implementation). The same issue is also noted with a personal code. Any idea of what's going on ?

@jiboune

This comment has been minimized.

Copy link

commented Apr 18, 2018

+1 Same problem, did you find a solution ?

@louisn

This comment has been minimized.

Copy link

commented Jul 24, 2018

+1 Same problem.

@louisn

This comment has been minimized.

Copy link

commented Jul 24, 2018

When setNotifyValue is executed on the Core Bluetooth Peripheral, it is expected that didUpdateNotificationStateFor will execute with success or error. This never happens. Also, didUpdateValue is never executed either. This is at the core (pun intended) of the issue. So far no solution for it that I've found.

@daphtdazz

This comment has been minimized.

Copy link
Owner

commented Jul 27, 2018

Hi all, sorry I haven't been very proactive on this, I'm going to prioritise it in the next week. I will keep you updated.

@daphtdazz daphtdazz added the bug label Sep 25, 2018

@louisn

This comment has been minimized.

Copy link

commented Jan 1, 2019

Bumping this issue. Any idea if it could be resolved soon?

@daphtdazz

This comment has been minimized.

Copy link
Owner

commented Jan 2, 2019

Hi @louisn, I think I should finally find time this week to fix this. I had been concentrating on getting the console implemented. It would be really helpful if you could get a repro using the latest version of WebBLE and with console logging, and then send me the logs, as I'm not quite sure what the issue is yet.

@louisn

This comment has been minimized.

Copy link

commented Jan 2, 2019

Great news @daphtdazz !
I'm using an app that works with Chrome on MacOS, Windows, and Android.
The app URL is https://moxydev-c829c.firebaseapp.com

BleBrowser won't connect the Moxy Monitor (namePrefix = Moxy). I'm not sure this is the same symptom as described in the issue. The XCode log shows this output.

2019-01-02 06:16:10.102069-0600 WebBLE[271:5754] Could not load IOSurface for time string. Rendering locally instead.
2019-01-02 06:16:11.143104-0600 WebBLE[271:5754] Did start provisional nav
2019-01-02 06:16:11.149700-0600 WebBLE[271:5754] WBLogManager clearLogs()
2019-01-02 06:16:11.170026-0600 WebBLE[271:5754] Bluetooth is ON
2019-01-02 06:16:39.889995-0600 WebBLE[271:5754] [MC] System group container for systemgroup.com.apple.configurationprofiles path is /private/var/containers/Shared/SystemGroup/systemgroup.com.apple.configurationprofiles
2019-01-02 06:16:39.894269-0600 WebBLE[271:5754] [MC] Reading from public effective user settings.
2019-01-02 06:16:40.740230-0600 WebBLE[271:5754] [Common] _BSMachError: port 15103; (os/kern) invalid capability (0x14) "Unable to insert COPY_SEND"
2019-01-02 06:16:41.262097-0600 WebBLE[271:5754] Could not signal service com.apple.WebKit.Networking: 113: Could not find specified service
2019-01-02 06:17:00.013539-0600 WebBLE[271:5754] Could not load IOSurface for time string. Rendering locally instead.
2019-01-02 06:17:38.345348-0600 WebBLE[271:5754] Did start provisional nav
2019-01-02 06:17:38.345476-0600 WebBLE[271:5754] WBManager clearState()
2019-01-02 06:17:38.357936-0600 WebBLE[271:5754] WBManager deinit
2019-01-02 06:17:38.358026-0600 WebBLE[271:5754] WBManager clearState()
2019-01-02 06:17:38.358968-0600 WebBLE[271:5754] WBLogManager clearLogs()
2019-01-02 06:17:38.360541-0600 WebBLE[271:6324] [CoreBluetooth] XPC connection invalid
2019-01-02 06:17:38.373333-0600 WebBLE[271:5754] Bluetooth is ON
2019-01-02 06:18:00.010611-0600 WebBLE[271:5754] Could not load IOSurface for time string. Rendering locally instead.
2019-01-02 06:18:24.381883-0600 WebBLE[271:5754] Did start provisional nav
2019-01-02 06:18:24.382010-0600 WebBLE[271:5754] WBManager clearState()
2019-01-02 06:18:24.384776-0600 WebBLE[271:5754] WBManager deinit
2019-01-02 06:18:24.384885-0600 WebBLE[271:5754] WBManager clearState()
2019-01-02 06:18:24.386125-0600 WebBLE[271:5754] WBLogManager clearLogs()
2019-01-02 06:18:24.394672-0600 WebBLE[271:6453] [CoreBluetooth] XPC connection invalid
2019-01-02 06:18:24.400628-0600 WebBLE[271:5754] Bluetooth is ON
2019-01-02 06:18:42.941840-0600 WebBLE[271:5754] Requesting device with filters [["namePrefix": Moxy]]
2019-01-02 06:18:42.942984-0600 WebBLE[271:5754] Scanning for peripherals... (services: [])
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
2019-01-02 06:19:00.010524-0600 WebBLE[271:5754] Could not load IOSurface for time string. Rendering locally instead.
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
2019-01-02 06:19:19.654242-0600 WebBLE[271:5754] User cancelled device selection.
2019-01-02 06:19:19.656390-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(false, "User cancelled", 1);
"
2019-01-02 06:19:31.062204-0600 WebBLE[271:5754] Requesting device with filters [["namePrefix": Moxy]]
2019-01-02 06:19:31.062391-0600 WebBLE[271:5754] Scanning for peripherals... (services: [])
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
Error parsing advertisement data: not a valid UTF-8 sequence
2019-01-02 06:19:51.457201-0600 WebBLE[271:5754] User cancelled device selection.
2019-01-02 06:19:51.458077-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(false, "User cancelled", 3);
"
2019-01-02 06:20:00.016361-0600 WebBLE[271:5754] Could not load IOSurface for time string. Rendering locally instead.

@louisn

This comment has been minimized.

Copy link

commented Jan 2, 2019

Upon further review, the previous comment isn't exactly the issue but still might be useful background information so I'm not deleting it. Yet.

The picker acted a bit differently than I was expecting but it does allow me to select the Moxy Monitor once the Done button is pressed.

Once the user selects the device the log is as follows. The receiveMessageResponse entries just continue on.

2019-01-02 06:56:00.203288-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, {"productVersion":0,"deviceClass":0,"vendorID":0,"uuids":[],"id":"22CA6419-862A-402E-A98B-9CC630A6D9D5","adData":{"serviceData":[],"txPower":0,"rssi":"-56","manufacturerData":"","appearance":"fakeappearance"},"productID":0,"name":"Moxy5 3045:5","vendorIDSource":0}, 4749);
"
2019-01-02 06:56:00.472198-0600 WebBLE[271:5754] Connecting to GATT on device <WebBLE.WBDevice: 0x2831af5d0>
2019-01-02 06:56:00.708603-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4751);
"
2019-01-02 06:56:00.722750-0600 WebBLE[271:5754] Starting discovering for service 6404D801-4CB9-11E8-B566-0800200C9A66
2019-01-02 06:56:00.727446-0600 WebBLE[271:5754] Starting discovering for service 0000180F-0000-1000-8000-00805F9B34FB
2019-01-02 06:56:00.734979-0600 WebBLE[271:5754] Starting discovering for service 0000180A-0000-1000-8000-00805F9B34FB
2019-01-02 06:56:00.737648-0600 WebBLE[271:5754] Starting discovering for service 00001805-0000-1000-8000-00805F9B34FB
2019-01-02 06:56:06.082474-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4761);
"
2019-01-02 06:56:06.083263-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4763);
"
2019-01-02 06:56:06.083872-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4765);
"
2019-01-02 06:56:06.086210-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4767);
"
2019-01-02 06:56:06.087245-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4769);
"
2019-01-02 06:56:06.095212-0600 WebBLE[271:5754] Start discovering characteristics for service 6404D801-4CB9-11E8-B566-0800200C9A66
2019-01-02 06:56:06.098056-0600 WebBLE[271:5754] Start discovering characteristics for service Battery
2019-01-02 06:56:06.099172-0600 WebBLE[271:5754] Start discovering characteristics for service Device Information
2019-01-02 06:56:06.100108-0600 WebBLE[271:5754] Start discovering characteristics for service Current Time
2019-01-02 06:56:06.100946-0600 WebBLE[271:5754] Start discovering characteristics for service Current Time
2019-01-02 06:56:11.182944-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4781);
"
2019-01-02 06:56:11.183694-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4783);
"
2019-01-02 06:56:11.184281-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4785);
"
2019-01-02 06:56:11.186209-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4787);
"
2019-01-02 06:56:11.186845-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4789);
"
2019-01-02 06:56:11.197888-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4791);
"
2019-01-02 06:56:11.202388-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4793);
"
2019-01-02 06:56:11.209195-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4795);
"
2019-01-02 06:56:11.212885-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4797);
"
2019-01-02 06:56:11.216274-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4799);
"
2019-01-02 06:56:16.396637-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4811);
"
2019-01-02 06:56:16.397416-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4813);
"
2019-01-02 06:56:16.398246-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4815);
"
2019-01-02 06:56:16.400716-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4817);
"
2019-01-02 06:56:16.401543-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4819);
"
2019-01-02 06:56:16.410940-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4821);
"
2019-01-02 06:56:16.413216-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4823);
"
2019-01-02 06:56:16.417617-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4825);
"
2019-01-02 06:56:16.420142-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4827);
"
2019-01-02 06:56:16.423330-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4829);
"
2019-01-02 06:56:21.434799-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4841);
"
2019-01-02 06:56:21.435702-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4843);
"
2019-01-02 06:56:21.436335-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4845);
"
2019-01-02 06:56:21.438704-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4847);
"
2019-01-02 06:56:21.439452-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4849);
"
2019-01-02 06:56:21.445432-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4851);
"
2019-01-02 06:56:21.450050-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4853);
"
2019-01-02 06:56:21.452268-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4855);
"
2019-01-02 06:56:21.459360-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4857);
"
2019-01-02 06:56:21.460384-0600 WebBLE[271:5754] --> execute js: "window.receiveMessageResponse(true, "Success", 4859);

@louisn

This comment has been minimized.

Copy link

commented Jan 2, 2019

Getting closer to some useful logs. Here is the use case. I don't see js execution for getCharacteristic values. I've added the logging for more detail. Something in how the transaction manager is setting up handlers perhaps? I tried to fix it but don't understand that well enough.

2019-01-02 08:52:35.879113-0600 WebBLE[340:20658] triage for transaction Transaction(id: 279, key: device:getPrimaryService)
2019-01-02 08:52:35.879884-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 279);
"
2019-01-02 08:52:35.881335-0600 WebBLE[340:20658] triage for transaction Transaction(id: 281, key: device:getPrimaryService)
2019-01-02 08:52:35.882110-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 281);
"
2019-01-02 08:52:35.883531-0600 WebBLE[340:20658] triage for transaction Transaction(id: 283, key: device:getPrimaryService)
2019-01-02 08:52:35.884126-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 283);
"
2019-01-02 08:52:35.887491-0600 WebBLE[340:20658] triage for transaction Transaction(id: 285, key: device:getPrimaryService)
2019-01-02 08:52:35.888340-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 285);
"
2019-01-02 08:52:35.889676-0600 WebBLE[340:20658] triage for transaction Transaction(id: 287, key: device:getPrimaryService)
2019-01-02 08:52:35.890309-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 287);
"
2019-01-02 08:52:35.892646-0600 WebBLE[340:20658] triage for transaction Transaction(id: 289, key: device:getCharacteristic)
2019-01-02 08:52:35.893190-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 289);
"
2019-01-02 08:52:35.900012-0600 WebBLE[340:20658] triage for transaction Transaction(id: 291, key: device:getCharacteristic)
2019-01-02 08:52:35.900542-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 291);
"
2019-01-02 08:52:35.905284-0600 WebBLE[340:20658] triage for transaction Transaction(id: 293, key: device:getCharacteristic)
2019-01-02 08:52:35.905834-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 293);
"
2019-01-02 08:52:35.907337-0600 WebBLE[340:20658] triage for transaction Transaction(id: 295, key: device:getCharacteristic)
2019-01-02 08:52:35.907823-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 295);
"
2019-01-02 08:52:35.912960-0600 WebBLE[340:20658] triage for transaction Transaction(id: 297, key: device:getCharacteristic)
2019-01-02 08:52:35.913402-0600 WebBLE[340:20658] --> execute js: "window.receiveMessageResponse(true, "Success", 297);
"
2019-01-02 08:52:35.917190-0600 WebBLE[340:20658] triage for transaction Transaction(id: 299, key: device:readCharacteristicValue)
2019-01-02 08:52:35.918062-0600 WebBLE[340:20658] self.peripheral.readValue for transaction Transaction(id: 299, key: device:readCharacteristicValue)
2019-01-02 08:52:35.919913-0600 WebBLE[340:20658] triage for transaction Transaction(id: 301, key: device:readCharacteristicValue)
2019-01-02 08:52:35.920957-0600 WebBLE[340:20658] self.peripheral.readValue for transaction Transaction(id: 301, key: device:readCharacteristicValue)
2019-01-02 08:52:35.922335-0600 WebBLE[340:20658] triage for transaction Transaction(id: 303, key: device:readCharacteristicValue)
2019-01-02 08:52:35.923092-0600 WebBLE[340:20658] self.peripheral.readValue for transaction Transaction(id: 303, key: device:readCharacteristicValue)
2019-01-02 08:52:35.925575-0600 WebBLE[340:20658] triage for transaction Transaction(id: 305, key: device:writeCharacteristicValue)
2019-01-02 08:52:35.927727-0600 WebBLE[340:20658] triage for transaction Transaction(id: 307, key: device:readCharacteristicValue)
2019-01-02 08:52:35.928558-0600 WebBLE[340:20658] self.peripheral.readValue for transaction Transaction(id: 307, key: device:readCharacteristicValue)

@daphtdazz

This comment has been minimized.

Copy link
Owner

commented Jan 4, 2019

Hmm, I'm struggling to reproduce the issue. I am able to readValue() ok and get responses. Are you also subscribing to value change notifications on the characteristic you're reading from? Or simply reading directly? Will keep looking over the weekend and if you get anymore logs they'd be appreciated, especially if you are able to enable nslog() in WBUtils.js and send the javascript console output as well!

@louisn

This comment has been minimized.

Copy link

commented Jan 5, 2019

@louisn

This comment has been minimized.

Copy link

commented Jan 14, 2019

Still setting this up - I wanted to get the clearest data possible for posting.
One observation though. When I use Safari Develop to connect to the iPad for browser troubleshooting something really strange happens. The application I'm attempting to use polls the BLE device every few seconds to update display information. Each poll opens a new Web Inspector window!

The inspector window title is as follows
Web Inspector - Louis' IPad Mini - WebBLE - JSContext

Does that indicate that a new document or other context is opened each poll? If so it could be that the BLE device or the transaction management is out of context?

I'll continue to attempt to get additional data from the logging output from a clean connection that demonstrates the issue.

@daphtdazz

This comment has been minimized.

Copy link
Owner

commented Jan 14, 2019

That sounds weird! When you say "poll" do you just mean you are calling readValue() every few seconds? Or some combination of writeValue() and readValue(), or something else?

Also, another option for handling this might be for me to get one of the devices that you're using and give it a go myself with your code? If they're readily available and not too expensive I could buy one, or better yet if you have a spare you could send me one :-)

@louisn

This comment has been minimized.

Copy link

commented Jan 14, 2019

@louisn

This comment has been minimized.

Copy link

commented Jan 15, 2019

I can get a MoxyMonitor device to you. Can you provide a shipping address to me at louis.naber@gmail.com.

@daphtdazz daphtdazz self-assigned this Apr 2, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.