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

Closed
PofNClimb opened this issue Mar 20, 2018 · 16 comments
Closed

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

PofNClimb opened this issue Mar 20, 2018 · 16 comments
Assignees
Labels

Comments

@PofNClimb
Copy link

@PofNClimb PofNClimb 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
Copy link

@jiboune jiboune commented Apr 18, 2018

+1 Same problem, did you find a solution ?

@louisn
Copy link

@louisn louisn commented Jul 24, 2018

+1 Same problem.

@louisn
Copy link

@louisn louisn 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
Copy link
Owner

@daphtdazz daphtdazz 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
Copy link

@louisn louisn commented Jan 1, 2019

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

@daphtdazz
Copy link
Owner

@daphtdazz daphtdazz 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
Copy link

@louisn louisn 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
Copy link

@louisn louisn 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
Copy link

@louisn louisn 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
Copy link
Owner

@daphtdazz daphtdazz 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
Copy link

@louisn louisn commented Jan 5, 2019

@louisn
Copy link

@louisn louisn 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
Copy link
Owner

@daphtdazz daphtdazz 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
Copy link

@louisn louisn commented Jan 14, 2019

@louisn
Copy link

@louisn louisn 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
@daphtdazz
Copy link
Owner

@daphtdazz daphtdazz commented Jun 19, 2019

Pretty sure this is fixed in 1.2.2 so closing.

@daphtdazz daphtdazz closed this Jun 19, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
4 participants