search

sputnikdev / eclipse-smarthome-bluetooth-binding

Eclipse SmartHome Bluetooth Binding
46 stars 10 forks source link

OH crashing when this is in use. #64

Open CrappyTan opened 6 years ago

CrappyTan commented 6 years ago

I've having a lot of crashes when this plugin is enabled. I am now running on Java Oracle 8. Not using Zulu like last time.

java version "1.8.0_181" Java(TM) SE Runtime Environment (build 1.8.0_181-b13) Java HotSpot(TM) Client VM (build 25.181-b13, mixed mode)

I've attached a dump file which was generated. I don't really know how to read them but I see lots of mention of this and tinyb. In particular, it mentions this -

r9 = 0x570bf328 {method} {0x570bf328} 'getCharacteristics' '()Ljava/util/List;' in 'tinyb/BluetoothGattService'

Could it be that something is failing when it's trying to read the characteristics and it's causing it to crash? This could be something unexpected in the Soma blinds I am using.

hs_err_pid22221.log

For reference, this is using the Soma blinds and running on an RPi 3B+.

Thoughts?

CrappyTan commented 6 years ago

Not sure if this helps or related?

21:32:30.335 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001533-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.340 [INFO ] [smarthome.event.ItemStateChangedEvent] - FrontRoomBlindsLeft_RSSI changed from -77 to -84
21:32:30.349 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.367 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while updating governor: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A / 86b366 : GDBus.Error:org.bluez.Error.Failed: Cancelled
21:32:30.370 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001531-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.398 [WARN ] [.impl.AbstractBluetoothObjectGovernor] - Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001527-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.434 [INFO ] [smarthome.event.ItemStateChangedEvent] - LocalServer_Storage_Available changed from 69.7 to 69.6
21:32:30.444 [INFO ] [smarthome.event.ItemStateChangedEvent] - LocalServer_Cpu_Load changed from 9.6 to 22.0
21:32:30.454 [WARN ] [manager.impl.CompletableFutureService] - Bluetooth error happened while completing a future immediately: /XX:XX:XX:XX:XX:XX/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001533-b87f-490c-92cb-11ba5ea5167c : Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001533-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.455 [WARN ] [manager.impl.CompletableFutureService] - Bluetooth error happened while completing a future immediately: /XX:XX:XX:XX:XX:XX/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.461 [INFO ] [smarthome.event.ItemStateChangedEvent] - LocalServer_Memory_Used changed from 49.6 to 50.5
21:32:30.480 [WARN ] [manager.impl.CompletableFutureService] - Bluetooth error happened while completing a future immediately: /XX:XX:XX:XX:XX:XX/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001527-b87f-490c-92cb-11ba5ea5167c : Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001527-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.488 [WARN ] [manager.impl.CompletableFutureService] - Bluetooth error happened while completing a future immediately: /XX:XX:XX:XX:XX:XX/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001531-b87f-490c-92cb-11ba5ea5167c : Error occurred while interacting (read) with native object: /B8:27:EB:5E:F9:17/F3:95:30:3E:DD:4A/00001861-b87f-490c-92cb-11ba5ea5167c/00001531-b87f-490c-92cb-11ba5ea5167c : GDBus.Error:org.bluez.Error.Failed: Not connected
21:32:30.503 [INFO ] [smarthome.event.ItemStateChangedEvent] - utility_boiler_heating_flow changed from 38.50 to 39.00
vkolotov commented 6 years ago

Hi @CrispinP, never seen this before. It seems to me there is something wrong with your native glibc.

Do you use anyUI on your PI? KDE?

vkolotov commented 6 years ago

What does this say for you?

pi@raspberrypi:~ $ ldd --version
ldd (Debian GLIBC 2.19-18+deb8u10) 2.19
Copyright (C) 2014 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
Written by Roland McGrath and Ulrich Drepper.
vkolotov commented 6 years ago

Probably something like that?

libc:glibc 2.24 NPTL 2.24
CrappyTan commented 6 years ago

Yup, it shows

[22:38:38] root@homeauto:/var/log# ldd --version
ldd (Debian GLIBC 2.24-11+deb9u3) 2.24
Copyright (C) 2016 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
Written by Roland McGrath and Ulrich Drepper.
vkolotov commented 6 years ago

Damn, they must have broken something. Did you install the OS on your rps from scratch? What version is it?

vkolotov commented 6 years ago

While I'm trying to understand what's wrong with that... Could you please try to use @xrucka 's transport? Please download it here: https://www.dropbox.com/s/qc154q1dwjnwh1h/bluetooth-manager-dbus-1.0-SNAPSHOT.jar?dl=0

You will need to uninstall TinyB transport, and put that file into /usr/share/openhab2/addons folder.

Please note, this binding is still in progress so definitely not the final version. Please let us know how it goes for you.

CrappyTan commented 6 years ago

I'll have a go tonight and let you know. I know it was dead again this morning so definitely not a java version issue. At least that's ruled out.

Is there someway I can get eclipse setup and debug it? Day job is a SQL DB specialist and know enough C# to be dangerous. Getting an environment set up might help solve the problem

vkolotov commented 6 years ago

Debugging java applications is very easy, I guess similar to C# app, you just connect from an IDE to a process. However, what we are dealing with is c and c++ stuff (TinyB and glibc :) ), so not very easy unfortunately...

I guess it is time to tackle this now and get rid of that nasty TinyB.

BTW, did you consider to get a BlueGiga adapter?

CrappyTan commented 6 years ago

not shy of that either. Been playing with Arduino for many years. Effort is in getting the environment setup. Happy to help where I can.

Give me an example of an adaptor I can try. I found one on Amazon for £15. AliExpress and BangGood are the same price. Worth getting one? How are they better?

vkolotov commented 6 years ago

Thanks.

Yes, definitely worth getting BlueGiga. These adapters are serial based with a ok-ish API, we have much more freedom in dealing with them.

I've got a couple of this:

https://www.aliexpress.com/item/Bluegiga-BLED112-Bluetooth-Smart-Dongle-Bluetooth-Smart-ready-for-Linux-Android-and-Windows-devices/32808005569.html?spm=a2g0s.9042311.0.0.27424c4d3yJcle

Not sure if they are genuine, but I was able to flash them with the newest firmware and also update configuration (default number of concurrent connection is 3, you can configure it to accept up to 8 connections).

I find that BlueGiga is also more sensitive, meaning that they discover more devices. However, the do no work with older version of BT (< 4.0) but that's not a problem nowadays as the main target is > 4.0 anyways.

CrappyTan commented 6 years ago

I've bought one of these - https://www.amazon.co.uk/gp/product/B06XRXVFFG/ref=oh_aui_detailpage_o02_s00?ie=UTF8&psc=1 Should be here tomorrow or Wednesday (Thursday in your time ;)). Will see if that changes things.

In the meantime, will try use the other addon you mentioned and see.

vkolotov commented 6 years ago

Sorry @CrispinP , I've attached wrong link to the dbus transport, here is a correct one: https://www.dropbox.com/s/2wh0hy822nzqu37/org.eclipse.smarthome.binding.bluetooth.transport.dbus-1.0-SNAPSHOT.jar?dl=0

CrappyTan commented 6 years ago

Ok, so interesting thing happened. It crashed (OH could no longer see that blinds) but a normal saving of the binding or restart of the service did not fix it. I ignored it, moved the two old transports out and put the new one in. No joy.

I rebooted the Pi and now it all sprang to life with the new transport. Lets see how that runs for a couple of days?

My new BT dongle should be arriving tomorrow or Thursday so will see if that is any better.

CrappyTan commented 6 years ago

Well, new dongle arrived and it does not work on the RPi. Works OK with Windows though.

The other transport does not work either. It still crashes.

This is getting very hard :(

vkolotov commented 6 years ago

Sorry to hear that, I'm sure it is resolvable.

Did you set up regex for your BLueGIga dongle? Pls check this: https://github.com/sputnikdev/eclipse-smarthome-bluetooth-binding#bluetooth-adapter

vkolotov commented 6 years ago

Obviously you will need to check if serial port is created for your BlueGiga adapter, e.g. /dev/ttyACM0. Or if you don't have any other serial devices connected to your RPI, just use this regexp to match everything: ((/dev/ttyACM)[0-9]{1,3})

CrappyTan commented 6 years ago

Man, I owe you a beer or 6. I thought it was just another BT adapter. I found a post which explains (like you did....) that it's a serial device. ALso has a nice python script to test it. https://docs-europe.electrocomponents.com/webdocs/12eb/0900766b812eb651.pdf

OK, so added and now have a thing which is online. :) Looking some more at the docs to see how to link this to the blinds instead of the normal BT adapter.

Thanks again for the help!

vkolotov commented 6 years ago

No worries. There is an abstraction layer in the Java Bluetooth Manager to work with adapters and devices from different transports, so for the binding there not any difference what physical adapter/transport is used. So should work out of the box for you for your "thing" that you have added when you used TinyB transport. :)

CrappyTan commented 6 years ago

I have disabled the on-board adapter just to make sure this one is working.

I now see OH error logs with this in:

23:09:37.918 [WARN ] [er.transport.bluegiga.BluegigaHandler] - Timeout received while calling complex procedure: BlueGigaGroupFoundEvent / BlueGigaProcedureCompletedEvent. Trying one more time
23:09:37.942 [WARN ] [ger.transport.bluegiga.BluegigaDevice] - Could not discover device attributes: bluegiga://88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C
org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaProcedureException: Could not initiate process: BlueGigaGroupFoundEvent / BlueGigaProcedureCompletedEvent / NOT_CONNECTED
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.callProcedure(BluegigaHandler.java:476) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.syncCallProcedure(BluegigaHandler.java:411) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.getServices(BluegigaHandler.java:206) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.discoverServices(BluegigaDevice.java:497) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.lambda$discoverAttributes$2(BluegigaDevice.java:432) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.runInSynchronizedContext(BluegigaHandler.java:190) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.discoverAttributes(BluegigaDevice.java:428) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.handleConnectionStatusEvent(BluegigaDevice.java:478) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.bluegigaEventReceived(BluegigaDevice.java:283) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at com.zsmartsystems.bluetooth.bluegiga.BlueGigaSerialHandler$2.run(BlueGigaSerialHandler.java:471) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

In my add-on folder I only have: org.eclipse.smarthome.binding.bluetooth.transport.bluegiga-1.2.2.jar org.eclipse.smarthome.binding.bluetooth-1.1.5.jar

Correct?

CrappyTan commented 6 years ago

Hold that thought! I was to hasty after the reboot. It's now connected to everything and working!

Thanks got your help! Seriously appreciate it. I will update in a day or two about stability.

C

vkolotov commented 6 years ago

BTW, I cut a new RC, the bundles you use are outdated ;) Just re-install them from the PaperUI.

CrappyTan commented 6 years ago

So it seems to crash again but for different reasons this time. In var/log/messages there is nothing about a service crash so that is a good step. However, looking at the connected status of the BT blinds they still disconnect after a while. Sometimes they reconnect, sometimes not. Saving the binding config ensures a successful connection.

Logs:


org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaProcedureException: Could not initiate process: BlueGigaGroupFoundEvent / BlueGigaProcedureCompletedEvent / NOT_CONNECTED
2018-09-27 06:55:20.158 [WARN ] [er.transport.bluegiga.BluegigaDevice] - Could not discover device attributes: bluegiga://88:6B:0F:A2:B2:4C/F3:95:30:3E:DD:4A
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.callProcedure(BluegigaHandler.java:476) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.syncCallProcedure(BluegigaHandler.java:411) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.getServices(BluegigaHandler.java:206) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.discoverServices(BluegigaDevice.java:497) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.lambda$discoverAttributes$2(BluegigaDevice.java:432) ~[272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaHandler.runInSynchronizedContext(BluegigaHandler.java:190) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.discoverAttributes(BluegigaDevice.java:428) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.handleConnectionStatusEvent(BluegigaDevice.java:478) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at org.sputnikdev.bluetooth.manager.transport.bluegiga.BluegigaDevice.bluegigaEventReceived(BluegigaDevice.java:283) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at com.zsmartsystems.bluetooth.bluegiga.BlueGigaSerialHandler$2.run(BlueGigaSerialHandler.java:471) [272:org.sputnikdev.org.eclipse.smarthome.binding.bluetooth.transport.bluegiga:1.2.2]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
    at java.lang.Thread.run(Thread.java:748) [?:?]

2018-09-27 06:56:06.290 [WARN ] [r.transport.bluegiga.BluegigaHandler] - Timeout received while calling simple procedure: BlueGigaAttributeValueEvent. Trying one more time
2018-09-27 06:56:06.316 [WARN ] [impl.AbstractBluetoothObjectGovernor] - Error occurred while interacting (read) with native object: /88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001526-b87f-490c-92cb-11ba5ea5167c : Could not initiate process: BlueGigaAttributeValueEvent / WRONG_STATE
2018-09-27 06:56:06.341 [WARN ] [impl.AbstractBluetoothObjectGovernor] - Error occurred while interacting (read) with native object: /88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : Could not initiate process: BlueGigaAttributeValueEvent / WRONG_STATE
2018-09-27 06:56:06.350 [WARN ] [anager.impl.CompletableFutureService] - Bluetooth error happened while competing a future: /XX:XX:XX:XX:XX:XX/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001526-b87f-490c-92cb-11ba5ea5167c : Error occurred while interacting (read) with native object: /88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001526-b87f-490c-92cb-11ba5ea5167c : Could not initiate process: BlueGigaAttributeValueEvent / WRONG_STATE
2018-09-27 06:56:06.377 [WARN ] [anager.impl.CompletableFutureService] - Bluetooth error happened while competing a future: /XX:XX:XX:XX:XX:XX/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : Error occurred while interacting (read) with native object: /88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : Could not initiate process: BlueGigaAttributeValueEvent / WRONG_STATE
2018-09-27 06:56:06.412 [WARN ] [anager.impl.CompletableFutureService] - Error occurred while completing (silently) futures: Error occurred while interacting (read) with native object: /88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001526-b87f-490c-92cb-11ba5ea5167c : Could not initiate process: BlueGigaAttributeValueEvent / WRONG_STATE
2018-09-27 06:56:06.444 [WARN ] [anager.impl.CompletableFutureService] - Error occurred while completing (silently) futures: Error occurred while interacting (read) with native object: /88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c : Could not initiate process: BlueGigaAttributeValueEvent / WRONG_STATE
2018-09-27 06:56:06.944 [WARN ] [.smarthome.model.script.Shed battery] - Turning off as it's 11.55V
2018-09-27 06:56:09.206 [WARN ] [er.transport.bluegiga.BluegigaDevice] - Disconnection event received bluegiga://88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C. Reason: CONNECTION_TIMEOUT.
2018-09-27 06:57:59.375 [WARN ] [er.transport.bluegiga.BluegigaDevice] - Disconnection event received bluegiga://88:6B:0F:A2:B2:4C/C1:03:74:91:05:6C. Reason: CONNECTION_TIMEOUT.
2018-09-27 06:58:27.570 [WARN ] [r.transport.bluegiga.BluegigaHandler] - Timeout has happened while sending a transaction, retry one more time: BlueGigaHelloCommand

Does this help any? Looks like you're managing to connect but then it's timing out which is odd (I will speak to the support guys about it if you want. They are also very helpful)

I will update to the latest version of the binding today and see if it helps

vkolotov commented 6 years ago

How far is your device? What's your RSSI readings? It might be that it is too far from the adapter, so the connection is not stable and times out... Just guessing

vkolotov commented 6 years ago

The error you attached above happens when it tried to connect, but the connection procedure failed to complete due to a disconnection event (I would say it is normal case, the binding expect it as BT protocol is a wireless protocol so it can happen). Normally after that it will try to recover its state, so it will try to connect again. Has it eventually established connection?

vkolotov commented 6 years ago

But you might be right, the device itself can drop connection for some reason. It really depends how it is coded etc. Maybe it expects some soft of authentication? Pin code? Maybe it is not supposed to keep connection always open... If you could confirm/ask with manufacturer, that would be great.

vkolotov commented 6 years ago

Just looking further into that piece of log, it does not show anything bad to me. It might indicate that the device is too far away from the adapter so it could not finish connection procedure. Then it tried to recover it's sate, but looks like the device was in wrong state (possibly it was in "connection establishing" state so it did not accept any other connection requests).

If the device dropped connection, we would see it in the log as a specific reason, e.g. something like "CLOSED BY CLIENT" or something, can't remember.

I'd say, if your RSSI readings is around 80-90, then I would not expect stable connection.

Also, Bluegiga adapters have max number of connection set to 3, how many devices/blinds do you have?

CrappyTan commented 6 years ago

At the moment I only have 2 clients so that is ok. I will need more though but that's a different topic.

RSSI - pretty grim actually. It bounces a lot in the -70s, sometimes in the -60s. Min, avg for today though -

Min: -98 Avg: -84.34375

I'll have to make a plan... Mesh?

vkolotov commented 6 years ago

Mesh is not supported, there are some talks on the forum to add support though. Not sure if your device supports it.

You could just try to position it properly, or I do really recommend a cable, even a short one, so that your adapter is not connected to rpi directly. Try to position your adapter so that RSSI is better (closer to -60 or higher, it is always confusing, -60 is better than -70 :) ).

vkolotov commented 6 years ago

If you live in a private house, you could put adapters in the roof cavity, that's what I do. Just above each room.

CrappyTan commented 6 years ago

I did move it to the end of a cable but made little difference.

I own my house so drilling holes is easy :) How can I put them in the ceiling and each room like you're suggesting? At the moment my servers are located in centre of the house. I will have blinds all over so I can't move a single unit closer.

I see 3 options: Multiple adapters somehow connected to same controller Multiple Pi running independently and reporting back (mqtt or HTTP) Different adapter with higher gain antenna.

I'm your opinion, options?

vkolotov commented 6 years ago

Well I did not drill holes. I have an rpi in the roof cavity (just in the middle) and usb cables spreading like spider.

I'd suggest to confirm it first, e.g. put your rpi closer to a device and see if it makes it more stable.

Yep, you can easily have multiple adapters that a connected to signle rpi through passive (5m max) or active (25m max) usb cables. Or you can set up usb-over-ip / serial-over-ip links as per this (I have never it tried it though, but definitely will have to do in future): https://community.openhab.org/t/forwarding-of-serial-and-usb-ports-over-the-network-to-openhab/46597

CrappyTan commented 6 years ago

I'll try that over the weekend. Thanks! (Just bought another gigablue :) )

CrappyTan commented 6 years ago

ok, got that working now and looking like we've got an rssi of around 55-60 which is muuuuch better. I'll see how it goes for a few days and report back 👍

vkolotov commented 6 years ago

Wow. I'm very surprised! How did you find my paypal account? :) Thank you very much!

How is it going? Any better?

CrappyTan commented 6 years ago

Easy ;)

It's much better but still with problems. Lots of disconnects which do reconnect by themselves sometimes. However, when it's disconnected, the blinds to not open. I've sent an email to the company for some help from them too. waiting on a reply.

C

vkolotov commented 6 years ago

Just thinking about it more. It might that Soma blind is designed in the such way. Let's say you live in average house and you have 10-15 windows/devices. As far as I understand, there is an app that controls them? If so, this means that single adapter controls them all. Hence, it is just not possible to keep all 15 connections constantly open. Therefore I believe your blind drops connection after some time to release it for some other device. You could possibly do an experiment with your phone.

Note down MAC address of a device. Set the "Connection control" to false. Then leave it for a while (maybe an hour or so?) and see if it stays online. I'd expect it to stay onlline, however it could be that it might stop advertising. Once you made sure that it stays online, pair that blind in your app. Try to control it. While you are controlling it, your phone should keep connection open, this would mean that the binding should stop seeing it and the "thing" should go offline (confirm this pls). Once it went offline, just leave the app open and lock your phone, or put the app into the background (just don't close it), then observe if after an hour or so the binding starts to see your device again (meaning that the app has disconnected from the device). This should prove my theory.

If it works like that, I'll need to come up with a special "mode" for BT things in OH which will not keep connection open and only connects when it is required (and then disconnects by a specific timeout). I was going to do this anyway, that would be a good exercise.

What do you think?

CrappyTan commented 6 years ago

Interesting theory. You're right on the multiple-blinds thing. Possibly cycle through the blinds in a group.

I tried it. As soon as I turn of the control option it disconnects and does not work any more. The phone though connects to it OK and gets the battery information but the BT addon does not. Have a look at this This is one of the blinds. You can see there is very little in the way of pattern (that I can see).

I've got a reply from the makers - they're looking at this thread and the plugin to try offer suggestion. They have this option which obviously does what we need. I would like to get an integrated solution though for openHAB - not via yet-another-bridge.

Onwards :)

vkolotov commented 6 years ago

Good stuff, hope they can contribute to this issue.

I tried it. As soon as I turn of the control option it disconnects and does not work any more.

This is what I'd expect. This is how Bluetooth works. You can only have a single simultaneous connection to a device. When you disable "connection control", the binding will disconnect from your blind allowing your phone to establish a new connection. Likewise, if the binding is connected to your blind, your phone won't be able to connect to your blinds.

The goal of that experiment is to confirm that the blind disconnects from your phone after some time when the app is not used.

But honestly speaking, I am pretty sure that we cannot keep connection always open because of that reason I mentioned earlier (when many blinds are used), it is just logical.

CrappyTan commented 6 years ago

See response from manufacturer. You're spot on. So, options are, per channel, specify a hold-connection timeout.

Our customers are using different ways to communicate with the shades, being it Amazon Alexa, Google Home, Apple HomeKit, Smart Shades app or even some other custom integration implemented by the customer or by the community. In many situations these options are used in parallel, requiring the product to enable each of these external apps to connect to the shades whenever required. Also, the timeout has been implemented as a precaution for the platforms which may undesirably leave the connection open making it impossible for other devices to connect.

We might consider implementing a way to hold the connection open forever in the future. Currently, it's possible to use reconnecting to the device as a workaround although this is not suggested because of the reasons brought up previously. All the other solutions currently, including the SOMA Connect, request info from the Smart Shades and connect to it only when required and do not hold a live connection all the time.

vkolotov commented 6 years ago

That's good. Now we know what's happening. I'll try to come up with something quick to test for you.

vkolotov commented 6 years ago

Just so you know, I've got a plan/design in my head and started to implement this. All the logic for connection management will go to the Bluetooth Manager. There will be a new attribute of the DeviceGovernor that represents "connection method". There will be 4 states for that attribute:

I'm going to implement EAGER first as it seems to me easier.

What do you think?

CrappyTan commented 6 years ago

I think that looks good. That will work for interactive items and channels such as MOVE-UP and MOVE-DOWN etc. But what about OH getting states? e.g. Battery level, position, are-you-there etc.

My thoughts - Clunky - a rule which polls the device. Extra overhead and not user-friendly Better - in the mapping definition you have a poll attribute. This is the frequency to connect. It can then request the value for it's characteristic and update the item. A bit like the network ping binding.

I'm happy to take your option first and write a rule to serve my second problem.

On Wed, 3 Oct 2018 at 10:48, Vlad Kolotov notifications@github.com wrote:

Just so you know, I've got a plan/design in my head and started to implement this. All the logic for connection management will go to the Bluetooth Manager. There will be a new attribute of the DeviceGovernor that represents "connection method". There will be 4 states for that attribute:

  • CONNECTED (existing state/logic, when BM tries to keep connection always open)
  • DISCONNECTED (existing state/logic, when BM tries to keep connection always off)
  • EAGER (new sate, connection gets established only when required, e.g. when a characteristic gets updated, right after work is done, the connection gets terminated/released)
  • LAZY (new state, similar to EAGER, but it does not disconnect after work is done, disconnection happens by timeout that is configurable by user)

I'm going to implement EAGER first as it seems to me easier.

What do you think?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/sputnikdev/eclipse-smarthome-bluetooth-binding/issues/64#issuecomment-426575555, or mute the thread https://github.com/notifications/unsubscribe-auth/Aal9TUZIjpYzCcGX5jv82gDVyRYjXkn3ks5uhIfXgaJpZM4W12yR .

vkolotov commented 6 years ago

Good catch. This can be resolved as you said (e.g. periodic log in and poll for all characteristics). In fact, this is how it work even now for characteristics that do not support notifications. This will need to be adjusted to support char that send notifications as well.

vkolotov commented 6 years ago

Hey @CrispinP, just an update. I did not have much time to finish it last week. Still working on some design issues. Hoping to get something this week.

CrappyTan commented 6 years ago

Hey Vlad,

not a problem. I have a workaround in place now. When you're ready I can put everything back to use your BL addon.

Cheers

On Sun, 7 Oct 2018 at 20:27, Vlad Kolotov notifications@github.com wrote:

Hey @CrispinP https://github.com/CrispinP, just an update. I did not have much time to finish it last week. Still working on some design issues. Hoping to get something this week.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/sputnikdev/eclipse-smarthome-bluetooth-binding/issues/64#issuecomment-427679737, or mute the thread https://github.com/notifications/unsubscribe-auth/Aal9TUvgXOWUaHVgLsklxOl11HKFfDPWks5uilWLgaJpZM4W12yR .