openHAB 2.0 binding

andreacioni

Can you post your node firmware version and log of OH2? It's very important for us to troubleshoot your problem.
Thanks!

kolaf

Hi all,

After battling with some radio issues with my sensors (in the RFM69 library) I am again ready to get things working using OH2. I downloaded the latest copy of the binding, but sadly things are not working for me. I believe the problem is still related to collecting to the serial port. I have lots of zwave stuff going on in my log, but i have included it anyhow in case someone feels the urge to take a look :-).
0_1461437647445_temporary log

andreacioni

@kolaf Same thing as @Francois, in the binding configuration try add this: skipStartupCheck=true.

kolaf

Thanks for the suggestion. I updated the configuration like this:

Bridge mysensors:bridge-ser:gateway [ serialPort="/dev/mysensorsUSB", sendDelay=200, skipStartupCheck=true ] {
	baro	stableBarometer	[ nodeId="6", childId="3" ]
	power	mainPower	[ nodeId="3", childId="1" ]
	temperature		basementTemperature		[ nodeId="10", childId="1"]
    }

It did not work as expected. The resulting log is like this:

    22:34:35.570 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'mysensors.things'
    22:34:35.606 [DEBUG] [col.serial.MySensorsSerialConnection] - Shutting down serial connection!
    22:34:35.606 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Stopping Writer thread
    22:34:35.606 [DEBUG] [g.mysensors.protocol.MySensorsReader] - Stopping Reader thread
    22:34:35.606 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge
    22:34:35.607 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/mysensorsUSB [baudRate:115200]
    22:34:35.614 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port.
    22:34:35.614 [DEBUG] [col.serial.MySensorsSerialConnection] - Waiting 5 seconds to allow correct reset trigger on serial connection opening
    22:34:40.608 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while calling thing updated at ThingHandler 'org.openhab.binding.mysensors.handler.MySensorsBridgeHandler@534c4d92: null
    java.util.concurrent.TimeoutException
            at java.util.concurrent.FutureTask.get(FutureTask.java:205)[:1.8.0_66]
            at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:179)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:72)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:56)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at org.eclipse.smarthome.core.thing.internal.ThingManager.thingUpdated(ThingManager.java:515)[94:org.eclipse.smarthome.core.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyTrackers(ThingRegistryImpl.java:218)[94:org.eclipse.smarthome.core.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:141)[94:org.eclipse.smarthome.core.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.core.thing.internal.ThingRegistryImpl.notifyListenersAboutUpdatedElement(ThingRegistryImpl.java:1)[94:org.eclipse.smarthome.core.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.core.common.registry.AbstractRegistry.updated(AbstractRegistry.java:102)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:57)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at org.eclipse.smarthome.core.common.registry.AbstractProvider.notifyListenersAboutUpdatedElement(AbstractProvider.java:82)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.access$3(GenericThingProvider.java:1)[118:org.eclipse.smarthome.model.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$18.apply(GenericThingProvider.java:700)[118:org.eclipse.smarthome.model.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.model.thing.internal.GenericThingProvider$18.apply(GenericThingProvider.java:1)[118:org.eclipse.smarthome.model.thing:0.8.0.201604051458]
            at org.eclipse.xtext.xbase.lib.IterableExtensions.forEach(IterableExtensions.java:399)[129:org.eclipse.xtext.xbase.lib:2.6.2.v201407030533]
            at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.modelChanged(GenericThingProvider.java:705)[118:org.eclipse.smarthome.model.thing:0.8.0.201604051458]
            at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:200)[107:org.eclipse.smarthome.model.core:0.8.0.201604051458]
            at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:116)[107:org.eclipse.smarthome.model.core:0.8.0.201604051458]
            at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:240)[107:org.eclipse.smarthome.model.core:0.8.0.201604051458]
            at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.access$1(FolderObserver.java:235)[107:org.eclipse.smarthome.model.core:0.8.0.201604051458]
            at org.eclipse.smarthome.model.core.internal.folder.FolderObserver$WatchQueueReader.processWatchEvent(FolderObserver.java:117)[107:org.eclipse.smarthome.model.core:0.8.0.201604051458]
            at org.eclipse.smarthome.core.service.AbstractWatchQueueReader.run(AbstractWatchQueueReader.java:95)[88:org.eclipse.smarthome.core:0.8.0.201604051458]
            at java.lang.Thread.run(Thread.java:745)[:1.8.0_66]
    22:34:40.612 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'mysensors:bridge-ser:gateway' has been updated.
    22:34:40.620 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'mysensors.things'
    22:34:40.815 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
    22:34:45.619 [ERROR] [s.internal.MySensorsBridgeConnection] - Cannot start reading/writing thread, probably sync message (I_VERSION) not received
    22:34:45.619 [DEBUG] [col.serial.MySensorsSerialConnection] - Shutting down serial connection!
    22:34:45.619 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Stopping Writer thread
    22:34:45.621 [WARN ] [g.mysensors.protocol.MySensorsWriter] - Writer thread interrupted
    22:34:45.621 [DEBUG] [g.mysensors.protocol.MySensorsReader] - Stopping Reader thread

kolaf

I restarted OH2 after changing the configuration, and this time I get no exceptions, but I see no more messages from the binding after the one included below.

@kolaf said:

22:34:40.815 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;

Edit: after a while I finally received a few packets in the debug console:

2016-04-23 23:10:49.020 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;d0;6t,
2016-04-23 23:10:49.021 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;4;1012.9

Both of the packets seem quite mangled, they are missing pieces, and some of the pieces present do not make sense. I have verified that the baud rate is correct, and when I correct directly to the Gateway using a serial console the output looks normal.

andreacioni

@kolaf that's my output, check if there's something different.

Have you tried rebooting the entire board/system?

23:08:55.305 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge
23:08:55.379 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/ttyS80 [baudRate:115200]
23:08:56.542 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port.
23:08:56.558 [DEBUG] [col.serial.MySensorsSerialConnection] - Waiting 5 seconds to allow correct reset trigger on serial connection opening
23:09:00.220 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR)
23:09:00.232 [WARN ] [ome.core.thing.internal.ThingManager] - Registering handler for thing 'mysensors:bridge-ser:gateway' takes more than 5000ms.
23:09:00.403 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'logging.persist'
23:09:00.623 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist'
23:09:01.380 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.rules'
23:09:01.615 [WARN ] [s.internal.MySensorsBridgeConnection] - Skipping I_VERSION connection test, not recommended...
23:09:01.641 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from UNINITIALIZED (HANDLER_INITIALIZING_ERROR) to ONLINE
23:09:01.733 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
23:09:01.737 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-ser, thing.id=mysensors:bridge-ser:gateway, service.id=319, service.bundleid=181, service.scope=singleton} - org.openhab.binding.mysensors
23:09:01.768 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;0;3;0;2;1.5
23:09:01.785 [DEBUG] [s.internal.MySensorsBridgeConnection] - Good,Gateway is up and running! (Ver:1.5)
23:09:04.490 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.script'
23:09:05.262 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.items'

EDIT: Do you see Skipping I_VERSION connection test, not recommended...?

kolaf

@andreacioni The difference is that I never get a response from the board for some reason. Connecting using screen works without issues. I think the still might be an issue with the serial lock, but given that we actually receive some data at all this might not be the case after all.

Edit: I have rebooted the board by unplugging it and reconnecting it.

andreacioni

@kolaf Could you try link the serial port to another name (ln -s /dev/mysensorsUSB /dev/ttyS80)

kolaf

I just tried disconnecting and reconnecting the board and restarting OH2 again, and this time it seems to have initialised correctly :-). I'm not sure why it didn't work the first two times, though.

andreacioni

@kolaf Perfect! ;)

kolaf

Now that things seem to be working on all levels, I have a very small request. Could someone please update the "baro" thing definition to include "V_PRESSURE" as well as "V_FORECAST"? My arduino is not big enough to calculate the forecast without running out of memory, so I can only send the actual barometric pressure.

Edit: Perhaps it is better to replace forecast with pressure for baro and create a new channel for the forecast?

What would also have been great, but this is a longer shot, would be to have some standardised way of getting received signal strength for the (at least directly connected) sensors. At least the RFM69 has an easy way of reporting RSSI, so just need a standard way of reporting this to the binding. Currently I'm reporting it as a generic debug message like this: 0;255;3;0;9;Received RSSI: -32

The reason I want to keep track of this is to keep an eye on the RF environments around my sensors. Things may change for many reasons (appliances, foliage, et cetera) and this will allow me to pre-emptively correct any problems in the future :-)

undee

@andreacioni

Here is the output generated after restarting the TimeAwareSensor sketch from the MySensors examples.

You can see that the I_TIME (3;0;1) message is received by the gateway several times, but it never sends a response to the node.

Do you need anything else?

12:20:59.677 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;Starting gateway (RNNGA-, 2.0.0-beta)
12:20:59.683 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;Radio init successful.
12:20:59.683 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;14;Gateway startup complete.
12:20:59.683 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;Init complete, id=0, parent=0, distance=0
12:20:59.683 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:2dc775c4' changed from INITIALIZING to ONLINE
12:20:59.776 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
12:20:59.782 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;2;2.0.0-beta
12:20:59.782 [DEBUG] [s.internal.MySensorsBridgeConnection] - Good,Gateway is up and running! (Ver:2.0.0-beta)
12:21:01.067 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=1,pt=0,l=0,sg=0:
12:21:01.071 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;3;0;1;
12:21:01.076 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=15,pt=0,l=2,sg=0:
12:21:01.119 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;send: 0-0-167-167 s=255,c=3,t=15,pt=0,l=2,sg=0,st=fail:
12:21:01.125 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=0,t=17,pt=0,l=10,sg=0:2.0.0-beta
12:21:01.128 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;0;0;17;2.0.0-beta
12:21:01.131 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=6,pt=1,l=1,sg=0:0
12:21:01.134 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;3;0;6;0
12:21:03.135 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=11,pt=0,l=5,sg=0:Clock
12:21:03.138 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;3;0;11;Clock
12:21:03.144 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
12:21:03.146 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;3;0;12;1.0
12:21:11.059 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=1,pt=0,l=0,sg=0:
12:21:11.061 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;3;0;1;
12:21:21.061 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=1,pt=0,l=0,sg=0:
12:21:21.063 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 167;255;3;0;1;
12:21:31.063 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 167-167-0 s=255,c=3,t=1,pt=0,l=0,sg=0:

andreacioni

Hi @TimO, me and @undee have tested everything (thanks again!). I'll push a little PR on github to fix a problem found in I_TIME response.

TimO

Hey @andreacioni & @undee , thanks for the test & fix!
I've merged the PR.

andreacioni

Hi @TimO ! I want to tell you an idea for the OH2 binding. What do you think about adding a date time channel to every thing that hold the last communication of the thing with the gateway? For example, it will be useful if you want to notify user that some sensors have become unavailable. Tell me what do you think! :)

kolaf

@andreacioni This can be easily done with a periodic rule that checks the latest update of the value assuming you have some persistence like rrd configured.

andreacioni

Hi @kolaf, yes this is how to do it. But my idea is to integrate the datetime channel into the binding in order to automatically update that value when updates are received. I think is better than have to do rules into OH config for each devices. What do you think?

kolaf

@andreacioni Sure, getting automatically configured alerts both for silent sensors and low battery for free would be great ☺️.

Denke

@andreacioni i support your idea to implementing this in the bindning.

TimO

Hi @andreacioni !

I can't decide if I like the idea or not. :-)
For sure, the result is needed. I currently have a rule that does store the last update from a sensor. In fact, I have a few rules, for all my battery powered sensors, so a reduction in the number of rules would be great.
BUT I suppose implementing this in the binding is not the OpenHAB-way, because the binding is only the interface to the hardware and should be lightweight.

openHAB 2.0 binding

15

11.7k

11.2k

113.0k