search

weliem / blessed-android

BLESSED, a Bluetooth Low Energy (BLE) library for Android
MIT License
552 stars 119 forks source link

Queue commands #5

Closed oliexdev closed 5 years ago

oliexdev commented 5 years ago

Could you write a bit how the queue command works?

Queueing commands, so you can don't have to wait anymore for the completion of a command before issueing the next command

For example if I send following commands to the Bluetooth device:

writeCharacteristic(A)
writeCharacteristic(B)
setNotify(XYZ)
writeCharacteristic(C)

then I assume all commands are queued executed on each success? Case A: invoke write A -> successful written A -> invoke write B -> successful written B -> set notfiy XYZ -> succesful notfied XYZ -> invoke write C -> successful written C

or are they only queued invoked but not wait for a successful completion? Case B: invoke write A -> invoke write B ->set notfiy XYZ -> invoke write C-> successful written B -> successful written A -> succesful notfied XYZ -> successful written C

For my program I need the case A but I think you implemented case B, am I right?

weliem commented 5 years ago

No I implemented A.

B would never work on Android.

If you look at the logcat you can verify that it is A.

Best

Martijn

On Wed, 21 Aug 2019, 18:45 OliE, notifications@github.com wrote:

Could you write a bit how the queue command works?

Queueing commands, so you can don't have to wait anymore for the completion of a command before issueing the next command

For example if I send following commands to the Bluetooth device:

writeCharacteristic(A) writeCharacteristic(B) setNotify(XYZ) writeCharacteristic(C)

then I assume all commands are queued executed on each success? Case A: invoke write A -> successful written A -> invoke write B -> successful written B -> set notfiy XYZ -> succesful notfied XYZ -> invoke write C -> successful written C

or are they only queued invoked but not wait for a successful completion? Case B: invoke write A -> invoke write B ->set notfiy XYZ -> invoke write C-> successful written B -> successful written A -> succesful notfied XYZ -> successful written C

For my program I need the case A but I think you implemented case B, am I right?

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/weliem/blessed-android/issues/5?email_source=notifications&email_token=ACT7HZ6KA4DP574I2XHLZS3QFVWMBA5CNFSM4IOJYRS2YY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4HGSEIBQ, or mute the thread https://github.com/notifications/unsubscribe-auth/ACT7HZ34A2SIR5PQTDBHXWLQFVWMBANCNFSM4IOJYRSQ .

weliem commented 5 years ago

...but considering your question, what is the problem you are having?

oliexdev commented 5 years ago

ok thanks for the clarification.

Well some Bluetooth devices which implemented Bluetooth really bad has a really long answer time.

If I log my command it looks like the following:

2019-08-21 19:10:15.937 Debug [1] BluetoothCommunication: Invoke write bytes [0D 12 10 01 00 00 E5 60 B4 01 14 55 5A 00 00 01 03 2A] on 0xffe9
2019-08-21 19:10:15.940 Debug [1] BluetoothCommunication: Step Nr 1
2019-08-21 19:10:15.944 Debug [1] BluetoothCommunication: Invoke write bytes [0D 0D 11 5D 5D 7A F7 00 00 00 00 00 91] on 0xffe9
2019-08-21 19:10:15.946 Debug [1] BluetoothCommunication: Step Nr 2
2019-08-21 19:10:15.948 Debug [1] BluetoothCommunication: Invoke set notification on 0xffe4
2019-08-21 19:10:15.950 Debug [1] BluetoothCommunication: Stop machine state
2019-08-21 19:10:15.971 Debug [1] MainActivity: Bluetooth connection successful established
2019-08-21 19:10:16.064 Debug [1] BluetoothCommunication: SUCCESS: Writing <0D 12 10 01 00 00 E5 60 B4 01 14 55 5A 00 00 01 03 2A> to <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:10:16.120 Debug [1] BluetoothCommunication: SUCCESS: Writing <0D 0D 11 5D 5D 7A F7 00 00 00 00 00 91> to <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:10:16.189 Debug [1] BluetoothCommunication: SUCCESS: Notify set for 0000ffe4-0000-1000-8000-00805f9b34fb
2019-08-21 19:10:16.191 Debug [1] BluetoothCommunication: Resume machine state
2019-08-21 19:10:16.192 Debug [1] BluetoothCommunication: Step Nr 3
2019-08-21 19:10:16.196 Debug [1] BluetoothCommunication: Invoke write bytes [0D 05 13 00 16] on 0xffe9
2019-08-21 19:10:16.199 Debug [1] BluetoothCommunication: Step Nr 4
2019-08-21 19:10:16.200 Debug [1] BluetoothCommunication: Invoke delayed disconnect in 60s
2019-08-21 19:10:16.259 Debug [1] BluetoothCommunication: SUCCESS: Writing <0D 05 13 00 16> to <0000ffe9-0000-1000-8000-00805f9b34fb>

But it only logs the execution of the command (in my source-code) and the successful response from the device. But I was not sure if you really wait internally for the successfull execution before you send the next command.

In issue https://github.com/oliexdev/openScale/issues/490 we have the case that we got a Bluetooth status code 8 (time out) which was one idea that the device might has a timing problem.

If I change my code that on each write command I wait for the success the Bluetooth connection works better!? But I am not really sure...

weliem commented 5 years ago

Hmmm, BLESSED is actually quite verbose and logs a lot of stuff in logcat. Are you not seeing anything of that? For example, when an actual write happens I log this:

Log.d(TAG, String.format("writing <%s> to characteristic <%s>", bytes2String(bytesToWrite), characteristic.getUuid()));

Perhaps the loggers are clashing somehow...

As for the issue you are referring to. From what I see in the log it is difficult to pinpoint the issue. It looks like the first write is simply not succeeding. After 5 seconds it times out. 5 seconds is a normal period that is typically negotiated in the connection settings. So if the scale doesn't respond this happens and you get error 8. However, in the log above everything seems normal and this is the same scale, right?

As usual I would first recommend replacing batteries....I remember seeing this before with the Yunmai scale is some of the other issues in your repo.

If it is not that I would really need to see the log statements from Blessed to figure out the issue...

oliexdev commented 5 years ago

well with my Yunmai scale it works but here are the complete logcat logs:

019-08-21 19:50:09.210 27088-27088/com.health.openscale D/BluetoothCommunication: Successful Bluetooth services discovered
2019-08-21 19:50:09.211 27088-27088/com.health.openscale D/BluetoothCommunication: Resume machine state
2019-08-21 19:50:09.211 27088-27088/com.health.openscale D/BluetoothCommunication: Step Nr 0
2019-08-21 19:50:09.218 27088-27088/com.health.openscale D/BluetoothCommunication: Invoke write bytes [0D 12 10 01 00 00 E5 60 B4 01 14 55 5A 00 00 01 03 2A] on 0xffe9
2019-08-21 19:50:09.220 27088-27088/com.health.openscale D/BluetoothCommunication: Step Nr 1
2019-08-21 19:50:09.223 27088-27088/com.health.openscale D/BluetoothCommunication: Invoke write bytes [0D 0D 11 5D 5D 84 51 00 00 00 00 00 C9] on 0xffe9
2019-08-21 19:50:09.224 27088-27088/com.health.openscale D/BluetoothCommunication: Step Nr 2
2019-08-21 19:50:09.225 27088-27088/com.health.openscale D/BluetoothCommunication: Invoke set notification on 0xffe4
2019-08-21 19:50:09.225 27088-27088/com.health.openscale D/BluetoothCommunication: Stop machine state
2019-08-21 19:50:09.248 27088-27103/com.health.openscale D/BluetoothGatt: onClientConnParamsChanged() - Device=60:64:05:A4:C9:XX interval=36 status=0
2019-08-21 19:50:09.272 27088-27088/com.health.openscale D/MainActivity: Bluetooth connection successful established
2019-08-21 19:50:09.279 27088-27088/com.health.openscale D/BluetoothPeripheral: writing <0d1210010000e560b40114555a000001032a> to characteristic <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:50:09.319 27088-27088/com.health.openscale D/ViewRootImpl@28c2de0[Toast]: ThreadedRenderer.create() translucent=true
2019-08-21 19:50:09.331 3655-12771/? V/MARsPolicyManager: handelAlertToastWindowStarted pkgName = com.health.openscale
2019-08-21 19:50:09.332 27088-27088/com.health.openscale D/InputTransport: Input channel constructed: fd=86
2019-08-21 19:50:09.333 27088-27088/com.health.openscale D/ViewRootImpl@28c2de0[Toast]: setView = android.widget.LinearLayout{6e9f899 V.E...... ......I. 0,0-0,0} touchMode=true
2019-08-21 19:50:09.335 27088-27088/com.health.openscale D/ViewRootImpl@28c2de0[Toast]: dispatchAttachedToWindow
2019-08-21 19:50:09.375 27088-27088/com.health.openscale D/ViewRootImpl@28c2de0[Toast]: Relayout returned: oldFrame=[0,0][0,0] newFrame=[333,2128][1106,2304] result=0x27 surface={isValid=true 547223072256} surfaceGenerationChanged=true
2019-08-21 19:50:09.376 27088-27088/com.health.openscale D/ViewRootImpl@28c2de0[Toast]: mHardwareRenderer.initialize() mSurface={isValid=true 547223072256} hwInitialized=true
2019-08-21 19:50:09.377 27088-27247/com.health.openscale D/mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000,  [773x176]-format:1
2019-08-21 19:50:09.381 27088-27088/com.health.openscale D/BluetoothCommunication: SUCCESS: Writing <0D 12 10 01 00 00 E5 60 B4 01 14 55 5A 00 00 01 03 2A> to <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:50:09.384 27088-27088/com.health.openscale D/BluetoothPeripheral: writing <0d0d115d5d84510000000000c9> to characteristic <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:50:09.384 27088-27088/com.health.openscale D/ViewRootImpl@28c2de0[Toast]: MSG_RESIZED_REPORT: ci=Rect(0, 0 - 0, 0) vi=Rect(0, 0 - 0, 0) or=1
2019-08-21 19:50:09.476 27088-27088/com.health.openscale D/BluetoothCommunication: SUCCESS: Writing <0D 0D 11 5D 5D 84 51 00 00 00 00 00 C9> to <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:50:09.476 27088-27088/com.health.openscale D/BluetoothGatt: setCharacteristicNotification() - uuid: 0000ffe4-0000-1000-8000-00805f9b34fb enable: true
2019-08-21 19:50:09.564 27088-27088/com.health.openscale D/BluetoothCommunication: SUCCESS: Notify set for 0000ffe4-0000-1000-8000-00805f9b34fb
2019-08-21 19:50:09.565 27088-27088/com.health.openscale D/BluetoothCommunication: Resume machine state
2019-08-21 19:50:09.566 27088-27088/com.health.openscale D/BluetoothCommunication: Step Nr 3
2019-08-21 19:50:09.568 27088-27088/com.health.openscale D/BluetoothCommunication: Invoke write bytes [0D 05 13 00 16] on 0xffe9
2019-08-21 19:50:09.569 27088-27088/com.health.openscale D/BluetoothCommunication: Step Nr 4
2019-08-21 19:50:09.570 27088-27088/com.health.openscale D/BluetoothCommunication: Invoke delayed disconnect in 60s
2019-08-21 19:50:09.573 27088-27088/com.health.openscale D/BluetoothPeripheral: writing <0d05130016> to characteristic <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:50:09.656 27088-27088/com.health.openscale D/BluetoothCommunication: SUCCESS: Writing <0D 05 13 00 16> to <0000ffe9-0000-1000-8000-00805f9b34fb>
2019-08-21 19:50:09.656 27088-27088/com.health.openscale D/BluetoothCommunication: Step Nr 4

But it seems some smartphones or scales has wired timeout problems. Maybe the commands are send to fast to the Bluetooth device?

weliem commented 5 years ago

Ok, that looks ok. You can also very clearly see here that 'Case A' is implemented...

BLESSED doesn't add any delay to commands. Once one command is completed, the next one is executed immediately without any delay. This should not be any problem in normal case. If there is a device that really needs a delay, then the delay is always needed and not sometimes. In other words, if your Yunmai scale is working fine and the other isn't then it is very unlikely that adding delays would solve anything.

I see a number of potential causes for the issue that was logged for OpenScale:

There is one more possibility and that it is a threading issue. I recently pushed a commit to fix a potential threading issue that could block the queue. It will be included in the next release but I think it is very unlikely that this is causing the issue. I never saw the threading issue in practice and only noticed it when doing code reviews.

weliem commented 5 years ago

I see in the OpenScale issue that the problem remains.... However, with the information in the log this guy sent, it is impossible for me to see what is causing the issue. I need more information.

Can you make the logcat statements of BluetoothPeripheral also appear in the logs that people send you? That would give a whole lot of more info....

Additionally, I released version 0.8 of Blessed. Upgrading to that version might also solve the issue if it was really a threading issue....

oliexdev commented 5 years ago

I use for my logging the external library Timber. I don't know how to log your log statements if you are not using the Timber library!?

I updated the version to 0.8 in openScale now.

weliem commented 5 years ago

Ok, well let's see if the 0.8 version fixes the issue.

I don't want to use Timber in my package. Blessed now has zero dependencies and I would like to keep it like that. Nice and clean... :-) But since debugging using logs like yours is really hard I am willing to think about how to make that easier.

So the only thing I can come up with now, is that I could add some more callbacks so that you can do the logging yourself. So for example:

What do you think?

P.S. You can also log a bit more yourself for the read/write/setNotify operations. These all return a boolean that indicates whether or not the operation has really been added to the queue. You currently ignore the returned boolean in BluetoothCommunication.java. So I would recommend to log something in case you receive a 'false'....

oliexdev commented 5 years ago

I had an e-mail contact with the same issue after he tested the dev version with the updated library and it works again but let us wait what @codepuregit will say.

Yeah, I can understand that and it is good that blessed is so lightweight. I would have decide the same.

More callbacks might be interesting. In my use case I need (mostly) for every operation in the queue the feedback from the BLE device. Only if I get a successful feedback from the previous operation I will step to the next operation. Currently I do it with some kind of a state machine in the BluetoothCommunication java class. Since Bluetooth is asynchron I have to stop the machine state to wait for the device response but this might be clever if you have some kind of "SuccessfulReplyOnOperation" callback.

Well, I guess if I programmed right they should be always successful added in your queue, isn't it? The characteristic and the operation support for the devices is known and will not changes.

weliem commented 5 years ago

Did the new version fix the issue?

oliexdev commented 5 years ago

I guess partially yes but we can close this issue for now if you want.

weliem commented 5 years ago

Ok, I see from the issue that there doesn't seem to be queue issue anymore. So closing this issue...

I will think about how to extend the list of callbacks so that you can do more logging and get back to you...