openHAB 2.0 binding

[TimO]

I've updated the first posting in this thread. You'll find the current repo there (also).

I've added a Wiki to the repo and made a brief description of the installation and configuration process.

https://github.com/tobof/openhab2-addons/wiki

The current binding (jar) is also in the repo now. You'll find the link in the wiki under "Installation".

Modifications in the current version:

• RollerShutter now supports STOP
• Performance of the binding improved. Big thanks to @andreacioni !!
• Stability improved. Also big thanks to @andreacioni
• Error handling on connection loss improved
• The baud rate of the serial gateway is now adjustable. (@andreacioni again!)
• some code cleanup: removed not needed debug output etc.

Please let me know if you found the time to test the binding and what the results are.

[Sebastián Zaffarano]

@TimO said:

I've updated the first posting in this thread. You'll find the current repo there (also).

I've added a Wiki to the repo and made a brief description of the installation and configuration process.

https://github.com/tobof/openhab2-addons/wiki

The current binding (jar) is also in the repo now. You'll find the link in the wiki under "Installation".

Modifications in the current version:

• RollerShutter now supports STOP
• Performance of the binding improved. Big thanks to @andreacioni !!
• Stability improved. Also big thanks to @andreacioni
• Error handling on connection loss improved
• The baud rate of the serial gateway is now adjustable. (@andreacioni again!)
• some code cleanup: removed not needed debug output etc.

Please let me know if you found the time to test the binding and what the results are.

Thank you @TimO !
This weekend I started migrating from my OH1.8 + mqtt GW setup to OH 2 beta + your binding. At the moment all is working fine, I spent some time learning about OH2 / Eclipse smartHome and watching your code, because I want to implement the smartSleep feature (https://github.com/mysensors/Arduino/pull/271) in the mysensors binding.

My idea is: when the handler don't receive an ACK from a message, it store the message for a while, waiting a heartbeat from a node, and, if the binding has some message stored for this node, then send it again. I don't know if this is correct, or if you thinks there is a better solution.

Regards

[TimO]

@Sebastián-Zaffarano said:

This weekend I started migrating from my OH1.8 + mqtt GW setup to OH 2 beta + your binding. At the moment all is working fine, I spent some time learning about OH2 / Eclipse smartHome and watching your code, because I want to implement the smartSleep feature (https://github.com/mysensors/Arduino/pull/271) in the mysensors binding.

My idea is: when the handler don't receive an ACK from a message, it store the message for a while, waiting a heartbeat from a node, and, if the binding has some message stored for this node, then send it again. I don't know if this is correct, or if you thinks there is a better solution.

That sounds like a good plan. The binding already uses a queue where messages that should be send are buffered and you are able to specify how long a message is hold in the queue (when it is time to send again).

I've already implemented a mechanism to request for an ACK message. This mechanism sends a message to the node, but holds this message in the queue and increments the number of retries (currently 4 retries, with different/longer delays). If the node responds with an ACK or the number of retries exceeds 4 the message is removed from queue. So you could indicate, with a configuration setting, that the node is an smartSleep node and thus only send the message once and if no ACK is received store the message for 10 minutes (for example) in the queue.

Here is the implementation: https://github.com/tobof/openhab2-addons/blob/MySensors/addons/binding/org.openhab.binding.mysensors/src/main/java/org/openhab/binding/mysensors/protocol/MySensorsWriter.java

BUT: The reader and the writer are working in different threads (asynchronus), so we have to sync the threads (the queue), if we receive an ACK and remove a message from the queue. I'm still struggling with that and that is the reason why the request for ACK should not be used at the moment and this will be a problem for smartSleep too.

According to the ACK feature: if the binding don't receive an ACK after 4 timeouts it will revert the status of the thing to the last value. So if you for example try to switch on your light and the message is not acknowledged, the binding will revert the switch state to off. I've removed the code for this, because of the issue above, but will add it again in the future.

[AndrewZ]

Hello everyone

I'm testing MySensor Ethernet gateway with a relay code on it. My understanding that Gateway stores the current state of the relay (or GPIO port) in it's EPROM. Can the binding periodically check the state of the port or should I rely on OH persistence functionality? Please advise what is the right way to keep the states synced between the Gateway and OH.

Thanks
Andrew

[TimO]

Hi Andrew!

Good question. Polling is currently not supported by the binding itself, but what you could do is: send a message from the node to the gateway, when the node restarts (the moment after you read the EEPROM and set the output of the pin).

Greetings
Tim

[AndrewZ]

@TimO , thanks for the idea.
So I can probably take some code used for reporting button presses in the examples and use it in the 'message'.

Thanks again
Andrew

[gonzalonal]

Hi Tim0.

I have read all your instructions in the GitHub Repo.
Is there any special reason why you suggest to add things in manual, text way, rather than with the PaperUI?

I have done it with the PaperUI and manually restarting my nodes and everything works just fine.

Let me know what you think.
Regards

[Qu3Uk]

I wondered that but I'm quite new to OpenHab so did some looking in to how various things work..

PaperUi uses something called MapDB which is basically a non-human readable configuration file. If you add "things" via PaperUi as far as I can tell you've still got to link the thing to an item for OpenHab to work with as far as I can tell..

I opted to do everything manually like in the wiki, seems much simpler

I get the impression PaperUi is still very new and not for production yet... its not compatible with sitemaps as they are waiting to implement a version of sitemaps in PaperUI or something.. I think it all boils down to the fact they want to keep V2 100% compatible with V1 configs and bindings etc so all the new stuff in V2 isn't quite ready yet...

Anyway might have totally got the wrong impression but that's what I see as a new OpenHab user going straight to v2.

On another note the work your doing TimO is awesome!

[TimO]

@gonzalonal

I totally agree with @Qu3Uk !
Both ways work and currently I like the configuration with the .items file more.

In an early version of the PaperUI it was possible to change the status of items (switch lights on and off). Maybe something like this will return or habmin2 will fill the gap.

[Denke]

I need support for HVAC device, how much work is there to be done to get that included.

I have made a thermostat controller for my Wirsbo floor project can be found under myprojects wirsbo uponor thermostat replacement

[TimO]

@Denke What is it exactly what you need? Which types?
How is the setpoint set (request/send)?

Greetings
Tim

[Denke]

@TimO
Hi Tim
I use gw.present(0, S_HVAC); to present the sensor to the controller

I use the following messages to send information
MyMessage msgTemp(0,V_TEMP); //temperature of thermostat
MyMessage msgFlowState(0,V_HVAC_FLOW_STATE); //tells if the thermostat is active HeatOn or off
MyMessage msgSetpointHeat(0,V_HVAC_SETPOINT_HEAT); //used for setting wanted temperature
MyMessage msgKnobTemp(0,V_VAR1); //gives the wanted manual temperature set on the thermostat knob (used for fallback when home automation dont work
MyMessage msgRunningMode(0,V_VAR2); //running mode internal or external internal = knob value used, external set by home automation
MyMessage msgHystLow(0,V_VAR3); //used if hysteresis needs to be changed (low value)
MyMessage msgHystHigh(0,V_VAR4); //used if hysteresis needs to be changed (high value)
MyMessage msgUpdateTime(0,V_VAR5); //used to set system sampling/update time

All of the above values are sent out from the thermostat at update sampling time interval.

V_HVAC_SETPOINT_HEAT(msgSetpointHeat), V_VAR3(msgHystLow), V_VAR4(msgHystHigh), V_VAR5(msgUpdateTime) can be set from the controller to update the thermostat parameters

[gonzalonal]

Hi TimO.

I am trying to do a gw.request from one of my nodes that requires the value of a numeric item from OpenHAB.

Have you tested this? I am unable to make it work.

I have created a rule:

rule "Heart Rate request"
when
	Item Heart_Rate received command
then
if (receivedCommand == "REQUEST")
{
	logInfo( "Heart Rate", "Heart rate request")
	sendCommand(Heart_Rate, Heart_Rate.state);
}
end

Please, let me know if I am doing it the wrong way.
Regards.

[Qu3Uk]

I seem to be having some issues with the dimmer function and I'm not entirely sure if its OpenHab, the binding or MySensors... but I seem to be able to crash the gateway once OpenHab boots up... The node is basically running DimmerLED stretch

20:31:13.030 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 7;1;1;0;0;33.8
...
20:31:13.596 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'Light_APT_Lounge_TV' received command ON
20:31:13.598 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 8;0;1;0;2;1
20:31:13.602 [INFO ] [marthome.event.ItemStateChangedEvent] - Light_APT_Lounge_TV changed from NULL to 100
20:31:14.599 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;0;3;0;14;Gateway startup complete.
20:31:27.963 [WARN ] [g.mysensors.protocol.MySensorsReader] - Connection to Gateway lost!
20:31:27.964 [DEBUG] [g.mysensors.protocol.MySensorsReader] - Stopping Reader thread
20:31:27.965 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:gateway' changed from ONLINE to OFFLINE

I notice the ItemState is null and that sort of makes sense why if OpenHab has been restarted but surely if it is null it shouldn't cause the gateway to go offline? Also it doesn't reconnect which is probably more of an issue.

Bridge mysensors:bridge-eth:gateway [ ipAddress="192.168.1.150", tcpPort=5003, sendDelay=200 ] {
        	dimmer			light08	[ nodeId="8", childId="0" ]	
}

Items

Dimmer	Light_APT_Lounge_TV	"TV Lights"	<light>	(Lights, APT_Lounge)	{ channel="mysensors:dimmer:gateway:light08:dimmer" }

[TimO]

I finally found some time to develop on the binding.

A new version is available with the following changes:

• On startup the binding will request I_VERSION from gateway to ensure its proper startup. Thanks @andreacioni for the PR!!

• HVAC (V_VAR1, V_VAR2 ...) are now available. Thanks @Denke for the PR!!

• The request for ACK feature is now available for testing. It works for light/status for me. If a message is NOT acknowledged by a node the binding retries to send the message five times. If no ACK is received after that the binding will try to revert the item to its old state. This only works, if a state is known (not NULL, for example at startup).

Additionally I've tested the binding with multiple gateways (one EthernetGW, one SerialGW), works fine.

[gonzalonal]

Hi @TimO.
I have just installed the new release and I believe I've found a little bug. I am using Serial Gateway with version 1.5.3

At boot up time, I am getting the followinf error:

03:07:52.644 [ERROR] [s.internal.MySensorsBridgeConnection] - Cannot start reading/writing thread, probably sync message (I_VERSION) not received

I have read that this new release, request the gateway for its version so as to prove proper start up.

What I have found is that the binding might be asking for the Gateway version al little too soon.

03:07:50.895 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
03:07:50.912 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;0;3;0;14;Gateway startup complete.
03:07:52.644 [ERROR] [s.internal.MySensorsBridgeConnection] - Cannot start reading/writing thread, probably sync message (I_VERSION) not received
03:07:52.647 [DEBUG] [col.serial.MySensorsSerialConnection] - Shutting down serial connection!
03:07:52.659 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Stopping Writer thread
03:07:52.661 [WARN ] [g.mysensors.protocol.MySensorsWriter] - Writer thread interrupted
03:07:52.666 [DEBUG] [g.mysensors.protocol.MySensorsReader] - Stopping Reader thread

I have tested this manually and found that the gateway ONLY answers its version after its startup is finished and the message "0;0;3;0;14;Gateway startup complete." is sent.

When the binding starts, It makes (somehow) the gateway to reboot. So, the gateway runs its setup() method and when it's done, it send the message "0;0;3;0;14;Gateway startup complete"

Let me know if you can reproduce this error. Maybe it's just some problem with my setup, but with the previus version I was having no issues.

Regards!

[andreacioni]

@gonzalonal I've implemented the check on startup. On serial gateway with the last version I'm not having any issue, so I would like to know: what hardware are you using? I think that probably is only a timing issue because, for exaple, Arduino UNO reset itself on opening connection and the message for request I_VERSION is sent immediately after connection is opened. I'll suggest you to try adding something like this:

Thread.sleep(3000)

After line 49 on MySensorsSerialConnection.java. Should become:

serialConnection = new NRSerialPort(serialPort, baudRate);
        if (serialConnection.connect()) {
            logger.debug("Successfully connected to serial port.");
            Thread.sleep(3000); 
            mysConReader = new MySensorsSerialReader(serialConnection.getInputStream(), this);
            mysConWriter = new MySensorsSerialWriter(serialConnection.getOutputStream(), this, sendDelay);

            connected = startReaderWriterThread(mysConReader, mysConWriter);
        } else {
            logger.error("Can't connect to serial port. Wrong port?");
        }

I can't do this test because I do not have an appropriate hardware, can you try the suggested code modification?

Thanks!

UPDATE: I've upload a temp build here: https://drive.google.com/file/d/0B11IarucpGdUdFJ2ZjVtZENsb2c/view?usp=sharing if you can't do the modification you can use this. Let me know!

[gonzalonal]

Hi @andreacioni. Thanks for your answer.
I have tested your custom build and it's working flawlessly.

09:10:36.913 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;0;3;0;14;Gateway startup complete.
09:10:37.161 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;

09:10:37.172 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;0;3;0;2;1.5.3
09:10:37.177 [DEBUG] [s.internal.MySensorsBridgeConnection] - Good,Gateway is up and running! (Ver:1.5.3)

Let me tell you about my hardware configuration. I am running OH2 Beta2 in a Raspberry Pi 2 Model B with an Arduino Nano V3 working as Serial Gateway directly connected to one of Rpi USB ports.

Please, let me know if you need me to some tests or maybe is just my config.
Thanks, regards.

[andreacioni]

@gonzalonal I've done all of my test on a custom ATMEGA328p shield for BeagleBone Black, running OH2 (beta) so the environment is the same but I've not the reset circuit that gives the issue above. So now I'll push this little fix on the github repo, I think there's nothing to to in this sense. Thank for your time !

If you find some other strange behaviour also remember that github repo has it's own issue tracker available here: https://github.com/tobof/openhab2-addons/issues, it works very well and is the best place to keep track of every software-releated bug

Greetings!

[TimO]

There is a new build of the jar available!

Changes:

• Added delay before checking the SerialGW (@andreacioni )
• Requests are answered by the binding (The binding returns "0" if no value was set before)

https://github.com/tobof/openhab2-addons/issues/8

[kolaf]

Are any of you having trouble with this binding together with other bindings that use serial ports? It looks as if the different bindings try to use the same serial port lock, so I get a conflict where things fail til initialize. Think it had something to do with the serial port library...

[TimO]

@kolaf Is it zwave again? Last time I tried to fix the conflict I needed to change the zwave binding.

[kolaf]

It is both zwave and rfxcom. I played about it in the oh2 community some time ago, let me see if I can find a link.

[kolaf]

It is my post: https://community.openhab.org/t/rfxcom-2-0-binding/4427/28?u=frankose

[gonzalonal]

Hello @TimO .

Just tested the last build of the binding. Works great.
I see you manage to answer the nodes requests without having to trigger a rule to respond.

I though that wasn't possible due to the limitation of the API. Did they manage to solve this from the OH side?

Does the binding itself keeps track of the items values, or does it querys OH (or its persistence service) for getting the right value?

Thanks!
Gonzalo

[TimO]

Hi @gonzalonal !

I'm glad it works, thanks for testing!
Sadly the limitation of the API is still there, but for the implementation of the requestAck feature I needed to implement a memory and now reused this memory to answer requests.

There is a really big BUT coming with this implementation: we currently can't use persistence out of the box. For this a rule is needed. After startup of OH we need to use "sendCommand(ITEMNAME, VALUE)", where VALUE Is the value stored in persistance. With that the memory of the binding is filled initially.
Hopefully I will find an easier way in the future .

[gonzalonal]

I get what you mean @TimO .

Unfortunatelly, using the rule method you suggest would create a lot of traffic (depending on how many sensors you have) at boot up time. Maybe there are some sensors that wouldn't behave the intended way if receiving the "last value" repeteadly.

An example. Lets supose I have an automatic gate, that everytime it receives a command, wether its a "1" or "0" it toggles its moving direction. Like the most common automatic gates remotes.

Gate is closed.

Press button > Gate opens
Press button > (if gate moving) Gate stops
Press button > (if gate open) Gate closes

Now, suppose last command send to the gate made it close. Suddenly, OH restarts itself because of power failure or whatever. It runs the rule to load the memory of the binding, while at the same time it sends to the sensors the last status taken from the persistance service. This would make the gate to open without your notice.

This may create dangerous escenarios.
I hope you can understand what I mean.

Maybe it would be a better idea to handle requests with rules in the way I suggested in the github issue, that is the same way as the OH-1 mysensors serial binding works.

Let me know if I can help in any way.
Regards.

Gonzalo.

[TimO]

@gonzalonal Good point!

If a request (or a message in general) is received there is no "commandReceived" in OH, so you can't trigger a rule based on a message received. So doing it with a rule is not possible.

A workaround would be to use "postUpdate()" to update the value after restart. This isn't implemented yet, but is no big deal. This would be a workaround for the workaround, because we still need the rule.

In the OH1 binding the request is answered with the state of the item, as I would like to to do too.
Line 277: https://github.com/bloft/openhab/blob/master/bundles/binding/org.openhab.binding.mysensors/src/main/java/org/openhab/binding/mysensors/internal/MySensorsBinding.java

[gonzalonal]

Hi @TimO . Good we got in the same page.

I think this topic needs some more thinking.

I was reading OH wiki and found this about receivedCommand.

 Implicit Variables inside the Execution Block

Besides the implicitly available variables for items and commands/states (see the script documentation), rules can have additional pre-defined variables, depending on their triggers:


* Every rule that has at least one command event trigger, will have the variable 
receivedCommand available, which can be used inside the execution block.

* Every rule that has at least one status change event trigger, will have the variable
previousState available, which can be used inside the execution block.

https://github.com/openhab/openhab/wiki/Rules

Maybe this is not available anymore, or at least on OH2.

For now, I think it would be a better approach to use postUpdate at systemStart to populate the binding memory. With this, we'll avoid sending commands to the nodes.

Regards!

[gonzalonal]

Hi again @TimO .

Just an idea.

What do you think about solving this problematic in this way:

We create a group whose members are all those items that later will populate the binding's memory. I have a group named mysqlpersisted where I put all the items whose data will be stored in my SQL DB. So I could use that group. For this example, let's call it "MemoryGroup"

Then, we can create the following rule:

rule "Populate MySensors binding memory"

when 
System started
then

(maybe add a delay to allow persistance services to load)

MemoryGroup?.members.forEach[i |
        postUpdate(i.name, i.previousState(true))
]

Using this method, memory would get populated everytime OH boots up, with data belonging to the persistance service that we use. And we use postUpdate, so no command is sent to the nodes.

With this I think we solve both problems as data in the binding will be concurrent with the persistance service data.

Let me know what you think about this.

Regards!

[TimO]

Hi @gonzalonal !

I was thinking in the same direction and I have played a litte bit with different rules. I had no success in finding a rule that worked. Additionally I don't like the workaround.

A good solution would be, to trigger a rule, if a request is received, but there too I had no success till now.

I'm still struggling with it ...

[tomkxy]

@TimO Do you think it would be hard to add MQTT support to the binding? I had a brief look to your code and it looks like the protocols are nicely isolated.

[TimO]

I'm currently trying to migrate my production environment from OH1 to OH2. I'm now using two serial gateways.

@kolaf : The problem you described occured to me too. In my case I use two serial gateways. I've added a little method that ensures that a connection to more than two serial ports via nrjavaserial is possible. It works within the OH2 binding. Could you test if it works with the RFXCOM binding you are using? A new jar is available on github. OH2 is currently using an old version of nrserialjava that has a bug. I don't know how to switch the version yet.

@tomkxy : I will integrate MQTT in my OH2 Installation soon and will come back to your request after that.

[undee]

The binding doesn't seem to handle the "requestTime" function yet. Time-aware sensors would be able to handle temporary OpenHAB outages by executing some scheduled actions autonomously, which I could use in the window cover controllers I'm developing.

[kolaf]

@TimO Thanks for the update. Unfortunately it did not seem to change anything for me, rfxcom still fails trying to use the wrong lock file. If it is helpful I can send you the log. Appreciate your input and effort.

[kolaf]

The weird thing is that it seems to work with an older version of OH2 (and an old version of your binding), but not with the more recent beta releases.

[TimO]

@kolaf : My guess is, the implementation in the could be the problem. Please do a litte test: remove the mysensors.jar file from the addons folder. Start OH2. RFXCOM should start fine now. Copy the mysensors.jar in the addons folder. OH2 will try to load the binding. What is the result?

I suppose this way both binding work fine together?!

[kolaf]

@TimO I tried this before, and removing the MySensors binding made the rfxcom binding work. However, this was not the case this time. I will try a bit later to also remove the zwave binding.

20:56:34.098 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:43b9314d' changed from UNINITIALIZED to INITIALIZING
20:56:34.115 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
20:56:34.115 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:43b9314d' changed from INITIALIZING to ONLINE
RXTX Warning:  Removing stale lock file. /var/lock/LCK..ttyACM0
20:56:34.361 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is     initialized
20:56:34.384 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave     controller
20:56:34.385 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to     5000ms. Soft reset is false.
20:56:34.419 [INFO ] [me.event.ThingStatusInfoChangedEvent] -     'zwave:serial_zstick:43b9314d' changed from ONLINE to     INITIALIZING
20:56:34.444 [INFO ] [smarthome.event.InboxUpdatedEvent   ] - Discovery Result     with UID     'sonos:zoneplayer:RINCON_5CAAFD2BB4D801400' has been updated.
20:56:34.578 [INFO ] [smarthome.event.InboxUpdatedEvent   ] - Discovery Result     with UID     'sonos:zoneplayer:RINCON_5CAAFD21C16201400' has been updated.
20:56:34.756 [INFO ] [smarthome.event.InboxUpdatedEvent   ] - Discovery Result     with UID     'sonos:zoneplayer:RINCON_5CAAFD2BB4FE01400' has been updated.
20:56:34.852 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
20:56:34.866 [INFO ] [smarthome.event.InboxUpdatedEvent   ] - Discovery Result with UID 'hue:bridge:0017881c7280' has been     updated.
20:56:34.869 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
20:56:34.998 [INFO ] [.openhab.core.internal.CoreActivator] - openHAB runtime has been started (v2.0.0, build 201602200203).
20:56:35.015 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.sitemap'
20:56:35.444 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysensors.things'
20:56:35.491 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:bridge-ser:gateway' has been added.
20:56:35.500 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from UNINITIALIZED to     INITIALIZING
RXTX fhs_lock() Error: opening lock file: /var/lock/LCK..ttyACM0: File exists. It is mine

�a�� testRead() Lock file failed
RXTX Warning:  Removing stale lock file. /var/lock/LCK..mysensorsUSB
20:56:37.420 [WARN ] [ssage.ApplicationCommandMessageClass] - NODE 37: Not initialized yet, ignoring message.
20:56:37.426 [ERROR] [WaveSerialHandler$ZWaveReceiveThread] - Protocol error (CAN), resending
20:56:37.427 [WARN ] [ssage.ApplicationCommandMessageClass] - NODE 37: Not initialized yet, ignoring message.
20:56:37.429 [WARN ] [ssage.ApplicationCommandMessageClass] - NODE 37: Not initialized yet, ignoring message.
20:56:38.773 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from INITIALIZING to ONLINE
20:56:38.774 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rfxcom.things'
20:56:38.780 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'rfxcom:bridge:rfxtrx' has been added.
20:56:38.790 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'rfxcom:bridge:rfxtrx' changed from UNINITIALIZED to INITIALIZING
20:56:38.792 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'rfxcom:bridge:rfxtrx' changed from INITIALIZING to OFFLINE
RXTX fhs_lock() Error: opening lock file: /var/lock/LCK..mysensorsUSB: File exists. It is mine

�`�� testRead() Lock file failed
20:56:38.805 [ERROR] [g.rfxcom.handler.RFXComBridgeHandler] - Connection to RFXCOM transceiver failed: null

[kolaf]

It appears that I get these errors even if I remove all the offending bindings. I think I need to start with a completely clean installation and see how it goes. I will let you know.

[kolaf]

Success, I think.

I started a brand-new installation of the latest OH2 snapshot, and sequentially added the rfxcom, z-wave, and mysensors bindings. After fiddling a bit with getting serial ports recognised by OH2 and getting the permissions correct, it seems to work. I still get some weird error messages, but apparently the library is able to work through its issues :-). An example of what I mean is included.

08:30:03.894 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:bridge-ser:334037be' has been added.
08:30:03.910 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:334037be' changed from UNINITIALIZED to INITIALIZING
RXTX fhs_lock() Error: opening lock file: /var/lock/LCK..rfxtrxUSB: File exists. It is mine

@�2� testRead() Lock file failed
RXTX fhs_lock() Error: opening lock file: /var/lock/LCK..ttyACM0: File exists. It is mine

@�2� testRead() Lock file failed
08:30:04.043 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_bridge_ser_334037be' has been added.
08:30:04.219 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_bridge_ser_334037be-mysensors:bridge-ser:334037be' has been added.
08:30:07.060 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:334037be' changed from INITIALIZING to ONLINE

[kolaf]

Returns out that I am still seeing the problem sometimes. If I change the configuration so that the bindings are reloaded (especially the zwav binding) it fails to reconnect to the serial port. I found someone who had posted an updated serial binding which supposedly solved some related problem (I think), but I'm not sure. It does not appear to have had any effect on the problem.

The modified version is available from one of the last posts here: https://github.com/openhab/openhab2-addons/issues/671

[kolaf]

I managed to get things working pretty well under Linux, but I have now switched to a Windows-based installation to see how that is.

Currently I have all three bindings working at the same time using three different serial ports. This is finally allowed me to pay attention to what the mysensors binding is doing.

The seems to be some kind of delay through the system for messages coming from the device. This is quite evident from the log included below. Device number three is a power sensor which transmits about once a minute. For some reason things are bunched together. I guess some of these could be Retransmissions, though. The sensor is located 4 m away from the gateway. Number 10 is a temperature sensor in the basement.

For some reason I have had severe problems getting the sensor to talk to the Gateway today. It shouldn't be related to the binding, I know, but I'm loosing my mind trying to keep track of all the different factors here.

2016-04-10 16:56:19.535 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 10;1;1;0;0;6.3
2016-04-10 16:56:20.512 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 10;1;1;0;0;6.3
2016-04-10 16:56:21.747 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 10;1;1;0;0;6.3
2016-04-10 16:56:21.805 [INFO ] [marthome.event.ItemStateChangedEvent] - FirstFloorHallMotionSensor changed from ON to OFF
2016-04-10 16:56:21.805 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_command changed from ON to OFF
2016-04-10 16:56:21.806 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_dimmingLevel changed from 100 to 0
2016-04-10 16:56:21.807 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_contact changed from OPEN to CLOSED
2016-04-10 16:56:24.922 [INFO ] [marthome.event.ItemStateChangedEvent] - FirstFloorHallMotionSensor changed from OFF to ON
2016-04-10 16:56:24.923 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_command changed from OFF to ON
2016-04-10 16:56:24.924 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_dimmingLevel changed from 0 to 100
2016-04-10 16:56:24.926 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_contact changed from CLOSED to OPEN
2016-04-10 16:56:55.048 [INFO ] [marthome.event.ItemStateChangedEvent] - CurrentDate changed from 2016-04-10T16:55:55.046+0200 to 2016-04-10T16:56:55.045+0200
2016-04-10 16:56:55.049 [INFO ] [ome.event.GroupItemStateChangedEvent] - ntp_ntp_local changed from 2016-04-10T16:55:55.046+0200 to 2016-04-10T16:56:55.045+0200 through ntp_ntp_local_dateTime
2016-04-10 16:56:55.049 [INFO ] [marthome.event.ItemStateChangedEvent] - ntp_ntp_local_dateTime changed from 2016-04-10T16:55:55.046+0200 to 2016-04-10T16:56:55.045+0200
2016-04-10 16:57:08.332 [INFO ] [marthome.event.ItemStateChangedEvent] - FirstFloorHallMotionSensor changed from ON to OFF
2016-04-10 16:57:08.333 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_command changed from ON to OFF
2016-04-10 16:57:08.334 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_dimmingLevel changed from 100 to 0
2016-04-10 16:57:08.334 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15669958_10_contact changed from OPEN to CLOSED
2016-04-10 16:57:13.444 [INFO ] [marthome.event.ItemStateChangedEvent] - MainHallMotionSensor changed from OFF to ON
2016-04-10 16:57:13.445 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15663466_10_command changed from OFF to ON
2016-04-10 16:57:13.450 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15663466_10_dimmingLevel changed from 0 to 100
2016-04-10 16:57:13.451 [INFO ] [marthome.event.ItemStateChangedEvent] - rfxcom_lighting2_A1WJD2HB_15663466_10_contact changed from CLOSED to OPEN
2016-04-10 16:57:23.053 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 10;1;1;0;0;6.3
2016-04-10 16:57:24.511 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 3;1;1;0;17;9223
2016-04-10 16:57:24.513 [INFO ] [marthome.event.ItemStateChangedEvent] - CurrentTotalPower changed from 6559 to 9223
2016-04-10 16:57:24.519 [INFO ] [marthome.event.ItemStateChangedEvent] - AverageTotalPower changed from 6559 to 9223
2016-04-10 16:57:24.798 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 3;1;1;0;17;9223
2016-04-10 16:57:25.616 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 3;1;1;0;24;4597
2016-04-10 16:57:27.075 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 3;1;1;0;24;4597
2016-04-10 16:57:29.766 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 3;1;1;0;24;4597
2016-04-10 16:57:31.128 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 3;1;1;0;18;4.6050

[TimO]

@kolaf : I'm glad the bindings are now working together.

The delay in the transmission is a bit strange. I've no idea where that could come from.
I've ported my production environment to OH2 and this didn't occure to me yet. I've upgraded a lot of my sensors to 2.0-beta and therefore took a closer look at the debug output of the OH2 binding to check if the devices present themself correctly and send the messages. I'll will keep an eye on it!

Currently I'm running OH2 with:

• Astro1
• Weather1
• MySensors2
• MySQL Persistence
• Sonos2

In the MySensors network I have a couple of Sensebender Micros, a shutter control with 12 SSR and two nodes to control LED lights plus selfmade DHT22 nodes connected to two gateways (one serial, one ethernet (iboard)).

I'm glad it runs stable for days now, although it is obvious in some places that this is a beta release of OH2. There are icons missing and there are bugs in the basicui and the documentation could be much better.

[Francois]

@TimO I try openHab 2.0 binding today and I am getting this where the serial changes from Initializing to Offline. Even if I reboot I get the same error. Why is this happing?

12:49:05.469 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge
12:49:05.543 [DEBUG] [col.serial.MySensorsSerialConnection] - Connecting to /dev/ttyUSB0 [baudRate:115200]
12:49:06.140 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_bridge_ser_bb7302f6' has been added.
12:49:06.390 [DEBUG] [col.serial.MySensorsSerialConnection] - Successfully connected to serial port.
12:49:06.446 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_bridge_ser_bb7302f6-mysensors:bridge-ser:bb7302f6' has been added.
12:49:09.409 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;Starting gateway (RRNGA-, 2.0.0-beta)
12:49:09.426 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;Radio init successful.
12:49:09.434 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;14;Gateway startup complete.
12:49:09.441 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;Init complete, id=0, parent=0, distance=0
12:49:09.506 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 0;0;3;0;2;
12:49:10.488 [WARN ] [ome.core.thing.internal.ThingManager] - Initializing handler for thing 'mysensors:bridge-ser:bb7302f6' takes more than 5000ms.
12:49:10.763 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 40-40-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
12:49:10.767 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;1;1;0;16;1
12:49:11.676 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 40-40-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
12:49:11.680 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;1;1;0;16;1
12:49:11.778 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 40-40-0 s=0,c=1,t=23,pt=2,l=2,sg=0:72
12:49:11.783 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;0;1;0;23;72
12:49:11.792 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 40-40-0 s=5,c=1,t=38,pt=7,l=5,sg=0:3.07
12:49:11.796 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;5;1;0;38;3.07
12:49:11.838 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 40-40-0 s=5,c=1,t=38,pt=7,l=5,sg=0:3.07
12:49:11.843 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;5;1;0;38;3.07
12:49:11.861 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 40-40-0 s=255,c=3,t=0,pt=1,l=1,sg=0:100
12:49:11.866 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;255;3;0;0;100
12:49:12.079 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 0;255;3;0;9;read: 66-66-0 s=1,c=1,t=24,pt=5,l=4,sg=0:3579898
12:49:12.083 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 66;1;1;0;24;3579898
12:49:14.409 [ERROR] [s.internal.MySensorsBridgeConnection] - Cannot start reading/writing thread, probably sync message (I_VERSION) not received
12:49:14.410 [DEBUG] [col.serial.MySensorsSerialConnection] - Shutting down serial connection!
12:49:14.412 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Stopping Writer thread
12:49:14.418 [WARN ] [g.mysensors.protocol.MySensorsWriter] - Writer thread interrupted
12:49:14.428 [DEBUG] [g.mysensors.protocol.MySensorsReader] - Stopping Reader thread
12:49:14.528 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-ser:bb7302f6' changed from INITIALIZING to OFFLINE
Insert Code Here

[andreacioni]

Hi @Francois ,

thanks for report. Seems that the you are using 2.0 version of MS Gateway. If you do not need it for particular task, try install the 1.5 version. I'll try to fix your problem as soon as possible!

[Francois]

@andreacioni Thanks for this all my sensor are running on version 2 so I don't know it my nodes will run on an 1.5 serial GW

[TimO]

I have a serial and ethernet gateway with version 2.0 running without any problems.
In your case there are a lot messages arriving within a short time, maybe that is the reason the gateway won't react on the I_VERSION message from the binding.

Please disable debugging in the gateway and try again. The reliability of my gateway improved a lot after disabling debugging.

[Francois]

@TimO I still get the same error after I disable debugging in the gateway

[andreacioni]

@Francois could you please send manually the I_VERSION command to the gateway? By no this is done by binding to check if the startup of the gateway was completed without errors. In your case that check fail. The I_VERSION message is this: 0;0;3;0;2;, you could try also 0;255;3;0;2; and see if gateway answer. Let we know what you see!

[Francois]

@andreacioni sorry how do I do this I_VERSION command to the gateway?

[andreacioni]

@Francois is a simple serial text message, just open the serial monitor of Arduino IDE and send it from there.

[Francois]

@andreacioni Here is is the info:

0;255;3;0;9;Starting gateway (RRNGA-, 2.0.0-beta)
0;255;3;0;9;Radio init successful.
0;255;3;0;14;Gateway startup complete.
0;255;3;0;9;Init complete, id=0, parent=0, distance=0
0;255;3;0;9;read: 40-40-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
40;1;1;0;16;1
0;255;3;0;9;read: 40-40-0 s=255,c=3,t=0,pt=1,l=1,sg=0:100
40;255;3;0;0;100
0;255;3;0;9;read: 40-40-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
40;1;1;0;16;1
0;255;3;0;9;read: 2-2-0 s=0,c=1,t=1,pt=7,l=5,sg=0:34.0
2;0;1;0;1;34.0
0;255;3;0;9;read: 40-40-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
40;1;1;0;16;0
0;255;3;0;9;read: 40-40-0 s=0,c=1,t=23,pt=2,l=2,sg=0:80
40;0;1;0;23;80
0;255;3;0;9;read: 40-40-0 s=255,c=3,t=0,pt=1,l=1,sg=0:100
40;255;3;0;0;100
0;255;3;0;9;read: 40-40-0 s=1,c=1,t=16,pt=0,l=1,sg=0:1
40;1;1;0;16;1
0;255;3;0;9;read: 101-101-0 s=255,c=3,t=15,pt=0,l=2,sg=0:

0;255;3;0;9;send: 0-0-101-101 s=255,c=3,t=15,pt=0,l=2,sg=0,st=fail:

0;255;3;0;9;read: 101-101-0 s=255,c=3,t=6,pt=1,l=1,sg=0:0
101;255;3;0;6;0
0;255;3;0;9;read: 101-101-0 s=255,c=3,t=6,pt=1,l=1,sg=0:0
101;255;3;0;6;0
0;255;3;0;9;read: 101-101-0 s=255,c=3,t=12,pt=0,l=3,sg=0:2.0
101;255;3;0;12;2.0

[andreacioni]

@Francois ok, this is the normal output. What happens if you send the I_VERSION message (just copy, paste and send one of them: 0;0;3;0;2; or 0;255;3;0;2; )?

UPDATE: Issue posted on tracker here

[TimO]

@Francois : I've updated my serial gw to the most recent development version and checked it against the binding. It is working for me. The response to I_VERSION does not belong to the RF, I've checked the current implementation of the MySensors library, so it should make not difference if you use RFM69, NRF or no RF at all.

Maybe the gateway is too busy to answer the request? Maybe we could an option for the binding to omit the check for I_VERSION? I'm out of ideas at the moment.

[Francois]

@TimO I have this gateway working on Domoticz without any problem. Put on OH2 I am getting this error and i don't know why it is happing

[andreacioni]

@TimO said:

Maybe we could an option for the binding to omit the check for I_VERSION?

I could do it without any problem.

[Francois]

@TimO I just download the last version of the beta version and recompile my gateway and I still am getting the same error code. There is not something that I missed in the MyConfig.h file or any other file that I need to change in openHAB2?

[TimO]

@Francois : No, I don't think so. I can't explain this behaviour and I'm sure the binding will just work fine after the initial check of I_VERSION.

@andreacioni : Would you be so kind to prepare a PR? I suggest to leave the check on by default.

[andreacioni]

@TimO simple update, tonight I'll push it

[TimO]

New version of the binding available!

• A requestTime from a node is now answered by the controller. Is anyone able to test it? (@undee )
• The controller will answer a request for "imperial or metric" like temperature sensors might ask. We need to test that too.

Big thanks @andreacioni for the implementation and @Francois for testing/reporting!

I've added an example page in the wiki: https://github.com/tobof/openhab2-addons/wiki/Examples
These are the type of things I'm currently using. (SensebenderMicro, Humidity, Temperature, Cover, Motion, Light ...)

Has anyone additional examples yet?

[undee]

@TimO

Thanks for your work! It's really nice to see the progress!

I have tried the TimeAwareSensor and the MockMySensors examples. The I_TIME message is sent by the node, obviously received by the gateway, but there the gateway is not sending anything in response. Are you sure your code for sending a time response is already active?

[Francois]

@TimO mysensor is now working The only problem I have and I also had the same problem with OpenHab 1.8.2 as well in that I don't get my relay sensor to switch on or off. If if look at the log openhab it is sending the commands to the RelayActuator what am I doing wrong with this sensor? All my other sensor are reporting back to the dashboard.

11:59:32.760 [INFO ] [smarthome.event.ItemCommandEvent    ] - Item 'teststudy' received command ON
11:59:32.769 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 101;1;1;1;2;1
11:59:32.782 [INFO ] [marthome.event.ItemStateChangedEvent] - teststudy changed from NULL to ON
11:59:32.789 [DEBUG] [g.mysensors.handler.MySensorsHandler] - handleUpdate called
11:59:32.873 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 101;1;1;1;2;1
11:59:32.977 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 101;1;1;1;2;1
11:59:33.478 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 101;1;1;1;2;1
11:59:34.479 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - Sending to MySensors: 101;1;1;1;2;1
11:59:35.209 [DEBUG] [g.mysensors.protocol.MySensorsReader] - 40;1;1;0;16;0
11:59:35.221 [INFO ] [marthome.event.ItemStateChangedEvent] - studymotion changed from OPEN to CLOSED
11:59:35.243 [INFO ] [marthome.event.ItemStateChangedEvent] - studymotionlastup changed from 2016-04-23T11:59:31.084+0200 to 2016-04-23T11:59:35.229+0200
11:59:35.269 [INFO ] [marthome.event.ItemStateChangedEvent] - studymotionlastup changed from 2016-04-23T11:59:35.229+0200 to 2016-04-23T11:59:35.248+0200
11:59:36.480 [WARN ] [g.mysensors.protocol.MySensorsWriter] - NO ACK from nodeId: 101
11:59:36.483 [DEBUG] [g.mysensors.protocol.MySensorsWriter] - No old status know to revert to!

[andreacioni]

Hi @undee

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.

[Denke]

Open query.
I think it is a bit boring that when you give the sensor a new adress that you have to power cycle the device to get it added. I can see that the sensor is starting to transmitt with the new address but The binding is not finding it as a new device. I can see that this happens becouse the sonsor dont present it self to the binding. how ever what about implementing a feature that asks the sensor for data when it just gave out a new address. I have also asked for mySensor to add the feature that when the node gets a new adress that it should present it self.

Which way do you see as best? Or is it nothing that can be one?

[hek]

https://github.com/mysensors/Arduino/pull/426

[Denke]

@hek SO if i understood it correctly from reading info from this link. My question below is answered by that it is beeing implemented as we sspeak?

[hek]

@Denke
Yes

[Denke]

Does the ack signaling work in the binding? I have a sensor that will request an ack from the gateway. Does anyone know if this is working?

[andreacioni]

@Denke yes acknowledge is actually implemented in binding

[Denke]

@andreacioni
Hi I have trouble finding out how to get my node to request ack, do you know how. I think i have figured out how to handle incoming message to check that the ack is received ant that is through message.isAck().

But how do i get the node to send a request for ack?

[Denke]

@Denke
You look and you look, then you ask someone how to do.

Then you look again and you find it:)
, true after the set message in send did the trick.
gw.send(msgSetpointHeat.set(setTemp,1),true);

[AffordableTech]

@TimO

ALMOST WORKING

Hi,
Ive been trying for ages to get a stable OpenHab + MySensors setup going. Your new binding is exactly what I've been hoping for and I'm so close to having it working, but can't see what I am doing wrong???

I've installed OpenHab2 plus your MySensors binding. I tried to follow your setup guide / otes, but I suspect a lot has changed since you wrote it.

What Works

• OpenHab runs without any errors in the log file {Yay!}

• My sensor data appears in the OpenHab log - ok.

• In OpenHab, my individual sensors are there and 'linked' to sensor channel.

• The date/time in browser from the NTP binding updates as expected.

Whats Wrong

• The items (in demo.items) appear in the browser, but no data values?

• I can see data from sensor changes in OpenHab log, but still NOT displayed?

Can anybody post an items, things and sitemap example file, or spot an error in mine?

My demo.items:

Number mywatts2 "Watts 2 [%.1f W]" <temperature> {channel="mysensors:power:503a021b:Power_21_6:watt"}

Number  mywatts1 "Watts 1 [%.1f W]" <temperature> {channel="mysensors:power:503a021b:Power_21_2:watt"


Number myhum01 "hum 1 [%.1f %RH]" <temperature> {channel="mysensors:humidity:7fbda972:hum"}

Number mytemp01 "Temp [%.1f C]" <temperature> {channel="mysensors:temperature:503a021b:Temperature_22_3:temp"

My demo.things:

yahooweather:weather:Dawesville [ location=28584781 ]
astro:sun:home  [ geolocation="-32.634619,115.638888", interval=60 ]
ntp:ntp:demo [ hostname="nl.pool.ntp.org", refreshInterval=60, refreshNtp=30 ]

Extract from my demo.sitemap:

  sitemap demo label="Main Menu" { 
    Frame { 
        Text item=mywatts1
        Text item=mywatts2 
        Text item=myhum01
        Text item=mytemp01 
    } 
  }

Initial startup from my openhab.log (apologies for the length)

2016-05-14 09:49:21.749 [DEBUG] [org.openhab.binding.mysensors       ] - BundleEvent STARTING - org.openhab.binding.mysensors
2016-05-14 09:49:21.760 [DEBUG] [org.openhab.binding.mysensors       ] - BundleEvent STARTED - org.openhab.binding.mysensors
2016-05-14 09:49:21.770 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=org.openhab.binding.mysensors.internal.MySensorsHandlerFactory, component.id=2, service.id=104, service.bundleid=10, service.scope=bundle} - org.openhab.binding.mysensors
2016-05-14 09:49:32.367 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'ipp:printer:Brother_MFC_8510DN' has been added.
2016-05-14 09:49:32.383 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=197, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.398 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:bridge-eth:503a021b' has been added.
2016-05-14 09:49:32.410 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:humidity:503a021b:Humidity_22_2' has been added.
2016-05-14 09:49:32.411 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:bridge-eth, thing.id=mysensors:bridge-eth:503a021b, service.id=198, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.436 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:humidity, thing.id=mysensors:humidity:503a021b:Humidity_22_2, service.id=199, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.438 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:humidity:7fbda972' has been added.
2016-05-14 09:49:32.441 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:40868d6c' has been added.
2016-05-14 09:49:32.444 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:503a021b:Power_21_1' has been added.
2016-05-14 09:49:32.447 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:503a021b:Power_21_2' has been added.
2016-05-14 09:49:32.448 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:503a021b:Power_21_3' has been added.
2016-05-14 09:49:32.452 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:503a021b:Power_21_4' has been added.
2016-05-14 09:49:32.455 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:503a021b:Power_21_5' has been added.
2016-05-14 09:49:32.456 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:power:503a021b:Power_21_6' has been added.
2016-05-14 09:49:32.458 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:temperature:503a021b:Temperature_22_3' has been added.
2016-05-14 09:49:32.459 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'mysensors:temperature:522d430d' has been added.
2016-05-14 09:49:32.460 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'ntp:ntp:local' has been added.
2016-05-14 09:49:32.477 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:humidity, thing.id=mysensors:humidity:7fbda972, service.id=200, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.497 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:40868d6c, service.id=201, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.500 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:503a021b:Power_21_1, service.id=202, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.502 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:503a021b:Power_21_2, service.id=203, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.505 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:503a021b:Power_21_3, service.id=204, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.511 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:503a021b:Power_21_4, service.id=205, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.514 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:503a021b:Power_21_5, service.id=206, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.520 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:power, thing.id=mysensors:power:503a021b:Power_21_6, service.id=207, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.523 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:temperature, thing.id=mysensors:temperature:503a021b:Temperature_22_3, service.id=208, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.525 [DEBUG] [org.openhab.binding.mysensors       ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandler}={thing.type=mysensors:temperature, thing.id=mysensors:temperature:522d430d, service.id=209, service.bundleid=10, service.scope=singleton} - org.openhab.binding.mysensors
2016-05-14 09:49:32.673 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:503a021b' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:32.699 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:503a021b:Humidity_22_2' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:32.712 [DEBUG] [nsors.handler.MySensorsBridgeHandler] - Initialization of the MySensors Bridge
2016-05-14 09:49:32.714 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:7fbda972' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:32.756 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - Connecting to bridge ...
2016-05-14 09:49:32.899 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:40868d6c' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:32.901 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - Connection to ethernet gateway successful!
2016-05-14 09:49:33.053 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:503a021b:Humidity_22_2' changed from INITIALIZING to ONLINE
2016-05-14 09:49:33.081 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:humidity:7fbda972' changed from INITIALIZING to ONLINE
2016-05-14 09:49:33.121 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:bridge-eth:503a021b' changed from INITIALIZING to ONLINE
2016-05-14 09:49:33.123 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_2' changed from INITIALIZING to ONLINE
2016-05-14 09:49:33.178 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:503a021b:Temperature_22_3' changed from INITIALIZING to ONLINE
2016-05-14 09:49:33.106 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 0;0;3;0;14;Gateway startup complete.
2016-05-14 09:49:33.200 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 0;0;3;0;2;1.5.1
2016-05-14 09:49:33.203 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_1' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.205 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_2' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.213 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_3' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.217 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_4' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.235 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_5' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.237 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_6' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.239 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:503a021b:Temperature_22_3' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.240 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:522d430d' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:33.242 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'CurrentDate-ntp:ntp:local:dateTime' has been added.
2016-05-14 09:49:33.254 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'hum01-mysensors:humidity:503a021b:Humidity_22_2:hum' has been added.
2016-05-14 09:49:33.255 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mywatts1-mysensors:power:503a021b:Power_21_2:watt' has been added.
2016-05-14 09:49:33.256 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mywatts1-mysensors:power:503a021b:Power_21_4:watt' has been added.
2016-05-14 09:49:33.263 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mywatts2-mysensors:power:503a021b:Power_21_5:watt' has been added.
2016-05-14 09:49:33.264 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'temp01-mysensors:power:503a021b:Power_21_5:watt' has been added.
2016-05-14 09:49:33.268 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'watts1-mysensors:power:503a021b:Power_21_5:watt' has been added.
2016-05-14 09:49:33.304 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'watts1-mysensors:power:503a021b:Power_21_6:watt' has been added.
2016-05-14 09:49:33.305 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'watts2-mysensors:power:503a021b:Power_21_2:watt' has been added.
2016-05-14 09:49:33.534 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'ipp_printer_Brother_MFC_8510DN-ipp:printer:Brother_MFC_8510DN' has been added.
2016-05-14 09:49:33.593 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:49:33.884 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:49:34.272 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_1' changed from INITIALIZING to ONLINE
2016-05-14 09:49:34.274 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_bridge_eth_503a021b-mysensors:bridge-eth:503a021b' has been added.
2016-05-14 09:49:34.275 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_humidity_503a021b_Humidity_22_2-mysensors:humidity:503a021b:Humidity_22_2' has been added.
2016-05-14 09:49:34.277 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_humidity_7fbda972-mysensors:humidity:7fbda972' has been added.
2016-05-14 09:49:34.278 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_40868d6c-mysensors:power:40868d6c' has been added.
2016-05-14 09:49:34.278 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_503a021b_Power_21_1-mysensors:power:503a021b:Power_21_1' has been added.
2016-05-14 09:49:34.279 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_503a021b_Power_21_2-mysensors:power:503a021b:Power_21_2' has been added.
2016-05-14 09:49:34.279 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_503a021b_Power_21_3-mysensors:power:503a021b:Power_21_3' has been added.
2016-05-14 09:49:34.280 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_503a021b_Power_21_4-mysensors:power:503a021b:Power_21_4' has been added.
2016-05-14 09:49:34.280 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_503a021b_Power_21_5-mysensors:power:503a021b:Power_21_5' has been added.
2016-05-14 09:49:34.281 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_power_503a021b_Power_21_6-mysensors:power:503a021b:Power_21_6' has been added.
2016-05-14 09:49:34.284 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_temperature_503a021b_Temperature_22_3-mysensors:temperature:503a021b:Temperature_22_3' has been added.
2016-05-14 09:49:34.295 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'mysensors_temperature_522d430d-mysensors:temperature:522d430d' has been added.
2016-05-14 09:49:34.347 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'ntp_ntp_local-ntp:ntp:local' has been added.
2016-05-14 09:49:34.557 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'ipp_printer_Brother_MFC_8510DN' has been added.
2016-05-14 09:49:34.560 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_bridge_eth_503a021b' has been added.
2016-05-14 09:49:34.576 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_4' changed from INITIALIZING to ONLINE
2016-05-14 09:49:34.581 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_humidity_503a021b_Humidity_22_2' has been added.
2016-05-14 09:49:34.584 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_humidity_7fbda972' has been added.
2016-05-14 09:49:34.589 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_40868d6c' has been added.
2016-05-14 09:49:34.589 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_503a021b_Power_21_1' has been added.
2016-05-14 09:49:34.591 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_503a021b_Power_21_2' has been added.
2016-05-14 09:49:34.592 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_503a021b_Power_21_3' has been added.
2016-05-14 09:49:34.593 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_503a021b_Power_21_4' has been added.
2016-05-14 09:49:34.594 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_503a021b_Power_21_5' has been added.
2016-05-14 09:49:34.596 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:temperature:522d430d' changed from INITIALIZING to ONLINE
2016-05-14 09:49:34.597 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_power_503a021b_Power_21_6' has been added.
2016-05-14 09:49:34.597 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_temperature_503a021b_Temperature_22_3' has been added.
2016-05-14 09:49:34.599 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:40868d6c' changed from INITIALIZING to ONLINE
2016-05-14 09:49:34.880 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'mysensors_temperature_522d430d' has been added.
2016-05-14 09:49:35.059 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'ntp_ntp_local' has been added.
2016-05-14 09:49:35.093 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_5' changed from INITIALIZING to ONLINE
2016-05-14 09:49:35.099 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_6' changed from INITIALIZING to ONLINE
2016-05-14 09:49:35.190 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'mysensors:power:503a021b:Power_21_3' changed from INITIALIZING to ONLINE
2016-05-14 09:49:42.498 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:49:43.626 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;174
2016-05-14 09:49:43.972 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2076
2016-05-14 09:49:44.806 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-05-14 09:49:45.008 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-05-14 09:49:45.503 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:45.976 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from INITIALIZING to ONLINE
2016-05-14 09:49:46.283 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ipp:printer:Brother_MFC_8510DN' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:46.285 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ipp:printer:Brother_MFC_8510DN' changed from INITIALIZING to OFFLINE
2016-05-14 09:49:46.979 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-05-14 09:49:47.057 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2016-05-14 09:49:47.812 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.sitemap'
2016-05-14 09:49:48.239 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.things'
2016-05-14 09:49:48.414 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'logging.persist'
2016-05-14 09:49:48.425 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'yahooweather:weather:Dawesville' has been added.
2016-05-14 09:49:48.726 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist'
2016-05-14 09:49:48.749 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.script'
2016-05-14 09:49:48.983 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'yahooweather:weather:Dawesville' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:48.984 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'yahooweather:weather:Dawesville' changed from INITIALIZING to ONLINE
2016-05-14 09:49:48.985 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'astro:sun:home' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:49.390 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'astro:sun:home' has been added.
2016-05-14 09:49:49.473 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'demo.items'
2016-05-14 09:49:49.566 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ntp:ntp:demo' changed from UNINITIALIZED to INITIALIZING
2016-05-14 09:49:49.737 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'ntp:ntp:demo' has been added.
2016-05-14 09:49:49.742 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mywatts2-mysensors:power:503a021b:Power_21_6:watt' has been added.
2016-05-14 09:49:49.743 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mywatts1-mysensors:power:503a021b:Power_21_2:watt' has been added.
2016-05-14 09:49:49.743 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'myhum01-mysensors:humidity:7fbda972:hum' has been added.
2016-05-14 09:49:49.744 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'mytemp01-mysensors:temperature:503a021b:Temperature_22_3:temp' has been added.
2016-05-14 09:49:50.090 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'astro:sun:home' changed from INITIALIZING to ONLINE
2016-05-14 09:49:50.608 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ntp:ntp:demo' changed from INITIALIZING to ONLINE
2016-05-14 09:49:53.619 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;70
2016-05-14 09:49:53.853 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1737
2016-05-14 09:49:54.166 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'ipp:printer:Brother_MFC_8510DN' changed from OFFLINE to ONLINE
2016-05-14 09:50:02.663 [WARN ] [stence.jpa.internal.JpaConfiguration] - Connection url is required in openhab.cfg!
2016-05-14 09:50:02.663 [WARN ] [stence.jpa.internal.JpaConfiguration] - Empty connection url in openhab.cfg!
2016-05-14 09:50:02.663 [WARN ] [stence.jpa.internal.JpaConfiguration] - Driver class is required in openhab.cfg!
2016-05-14 09:50:02.666 [WARN ] [stence.jpa.internal.JpaConfiguration] - Empty driver class in openhab.cfg!
2016-05-14 09:50:02.666 [INFO ] [stence.jpa.internal.JpaConfiguration] - user was not specified!
2016-05-14 09:50:02.673 [INFO ] [stence.jpa.internal.JpaConfiguration] - password was not specified!
2016-05-14 09:50:02.673 [INFO ] [stence.jpa.internal.JpaConfiguration] - syncmappings was not specified!
2016-05-14 09:50:02.724 [INFO ] [core.karaf.internal.FeatureInstaller] - Installed 'openhab-persistence-jpa'
2016-05-14 09:50:03.283 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;0;1;0;37;0
2016-05-14 09:50:03.591 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:50:03.856 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:50:08.636 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:50:13.592 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;167
2016-05-14 09:50:13.859 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2095
2016-05-14 09:50:23.600 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;71
2016-05-14 09:50:23.861 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1744
2016-05-14 09:50:33.595 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:50:33.855 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:50:34.786 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:50:43.593 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;170
2016-05-14 09:50:43.862 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2113
2016-05-14 09:50:53.596 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;69
2016-05-14 09:50:53.860 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1751
2016-05-14 09:51:00.926 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;12
2016-05-14 09:51:03.595 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:51:03.860 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:51:09.380 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;1;1;0;37;17
2016-05-14 09:51:13.594 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;170
2016-05-14 09:51:13.855 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2131
2016-05-14 09:51:23.597 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;71
2016-05-14 09:51:23.862 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1758
2016-05-14 09:51:29.115 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:51:31.920 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;255;0;0;17;1.5.1
2016-05-14 09:51:32.131 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;255;3;0;6;0
2016-05-14 09:51:32.520 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;255;0;0;17;1.5.1
2016-05-14 09:51:32.732 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;255;3;0;6;0
2016-05-14 09:51:33.958 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;255;3;0;11;Lounge Environs
2016-05-14 09:51:34.219 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;255;3;0;12;1.1
2016-05-14 09:51:34.478 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;2;0;0;7;
2016-05-14 09:51:34.739 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;3;0;0;6;
2016-05-14 09:51:35.000 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;1;1;0;43;2.5 ppm
2016-05-14 09:51:35.264 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;255;3;0;11;Energy Meter
2016-05-14 09:51:35.525 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;0;0;13;
2016-05-14 09:51:35.787 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;0;0;13;
2016-05-14 09:51:36.049 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;43;KwHours
2016-05-14 09:51:36.313 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;43;KwHours
2016-05-14 09:51:36.570 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;43;Watts
2016-05-14 09:51:36.831 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;3;1;0;0;24.1
2016-05-14 09:51:55.263 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:51:55.833 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;69
2016-05-14 09:51:56.094 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1698
2016-05-14 09:52:05.837 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:52:06.104 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:52:15.832 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;171
2016-05-14 09:52:16.093 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.1998
2016-05-14 09:52:21.403 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:52:25.833 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;68
2016-05-14 09:52:26.099 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1704
2016-05-14 09:52:35.837 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:52:36.102 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:52:37.110 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;0;1;0;37;0
2016-05-14 09:52:45.833 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;167
2016-05-14 09:52:46.095 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2016
2016-05-14 09:52:47.542 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:52:55.838 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;70
2016-05-14 09:52:56.108 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1711
2016-05-14 09:53:05.835 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:53:06.105 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:53:13.694 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:53:15.836 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;174
2016-05-14 09:53:16.097 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2034
2016-05-14 09:53:25.839 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;70
2016-05-14 09:53:26.099 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1718
2016-05-14 09:53:35.835 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:53:36.096 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:53:39.845 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:53:45.835 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;172
2016-05-14 09:53:46.095 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2053
2016-05-14 09:53:55.836 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;68
2016-05-14 09:53:56.098 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1724
2016-05-14 09:54:05.837 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:54:06.100 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:54:08.040 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:54:14.044 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;0;1;0;37;0
2016-05-14 09:54:15.840 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;174
2016-05-14 09:54:16.102 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2071
2016-05-14 09:54:25.839 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;68
2016-05-14 09:54:26.100 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1729
2016-05-14 09:54:34.176 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:54:35.836 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:54:36.096 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:54:45.843 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;173
2016-05-14 09:54:46.105 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2089
2016-05-14 09:54:49.812 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;2;1;0;1;55.3
2016-05-14 09:54:55.837 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;68
2016-05-14 09:54:56.102 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1734
2016-05-14 09:55:00.313 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:55:05.851 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:55:06.117 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:55:15.837 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;166
2016-05-14 09:55:16.107 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2108
2016-05-14 09:55:25.836 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;68
2016-05-14 09:55:26.108 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1739
2016-05-14 09:55:26.463 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:55:35.838 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:55:36.098 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:55:45.838 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;170
2016-05-14 09:55:46.106 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2126
2016-05-14 09:55:50.716 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 22;0;1;0;37;0
2016-05-14 09:55:52.609 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 50;0;1;0;37;11
2016-05-14 09:55:55.839 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;1;1;0;17;67
2016-05-14 09:55:56.101 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;4;1;0;18;93.1743
2016-05-14 09:56:05.838 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;2;1;0;17;0
2016-05-14 09:56:06.098 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;5;1;0;18;32.4534
2016-05-14 09:56:15.839 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;3;1;0;17;168
2016-05-14 09:56:16.099 [DEBUG] [rs.protocol.ip.MySensorsIpConnection] - 21;6;1;0;18;345.2144

All suggestions appreciated...

Thanks,

Paul

[TimO]

The things are not linked to items, therefore the items do not update. You have configured the bridge via PaperUi, correct? This should work, but I haven't tested it. Could you try to configure the gateway in the things file instead?
Have you seen the examples in the github wiki?
I'm currently on my mobile, so I can't say more at the moment.

[AffordableTech]

@TimO

Hi Tim,
Thanks for replying so promptly , trying to get this going over the weekend.

From what I can see, the fields are linked. I base this on the fact that the log file shows 'link added' and 'link removed' as I play with the 'demo.things' file.
Also, I get the same messages in the log etc, whether I create the links via the things file or with the paper-ui. I've also noticed that when I do make a typing mistake with an items or things entry, OpenHab is usually quick to spit out an error[s], implying that the corrected text is passing the syntax check.

I have stripped my demo to the bare minimum and have included my current set here. The first two (MySensors) 'items' do not update but the log file shows no error. The third item is linked to a non MySensors binding and it works regardless of whether I use to paper.ui or create the links manually (which helps me believe I am creating the link to the binding correctly.

My sitemap.demo

  sitemap demo label="Test Menu" { 
    Frame { 
        Text item=myhum01
        Text item=mytemp01 
        Text item=mytemp99 
    } 
  }

My items.demo

Number myhum01 "Humidity Test (22:2) [%.1f RH]" { channel="mysensors:humidity:gateway:myhum01:hum" }

Number mytemp01 "Temperature Test (22:3) [%.1f] °C" { channel="mysensors:temperature:gateway:mytemp01:temp" }

Number mytemp99 "Printer queue [%.0f jobs]" {channel="ipp:printer:Brother_MFC_8510DN:waitingJobs"}

QUESTION:
In the following things entry, should the first line start with "Bridge" or without? The binding setup notes appear to show both with and without?

My things.demo

Bridge mysensors:bridge-eth:gateway [ ipAddress="192.168.1.70",   tcpPort=5003, sendDelay=200 ] {
    /** define things connected to that bridge here */
    humidity        myhum01   [ nodeId="22", childId="2" ]
    temperature     mytemp01  [ nodeId="22", childId="3" ]
}

I always look for 'what I am doing wrong', but I have been on this for days with no joy, I've reached the point where I am really starting to suspect there may be a bug.

Once again, I would appreciate suggestions from anybody...

Thanks,

Paul

[Denke]

Hi all
Im having major difficulties getting openhab to discover my serial gateway. I have had it working and i have got input from my sensors. But every know and then when i have restarted the computer the serial gateway is offline. The COM port is active and working according to Windows.
I have tried to restart the computer, unplug and plug the usb several times. Doing this i have at some occasions got everything to work again.

Any suggestions what it can be that is being the problem.

I also think i have found a bug.

If i for example take the gateway or an sensor that has been added which is marked off line. Then if i press edit on that one and just press the "save" button then it shows that it is on line even though i seriously doubt it is. As i dont get data from my sensors.

Also how do i get the debug window (console view) to show for openhab?

[TimO]

@AffordableTech Hmmm, your configuration looks good. Please show me the debug output.

According the use of Bridge: I suppose using the word Bridge at the beginning is the right way!

@Denke: I haven't used OH2 on Windows yet, but I suppose you see the karaf console?

If so, you should be able to use: log:set DEBUG org.openhab.binding.mysensors and log:tail.

The online/offline status of a thing in OH2 only shows if the bridge is connected and if the thing could be initialized. There is no dependence to wether a thing has received data or not.

[Denke]

@TimO said:

log:set DEBUG org.openhab.binding.mysensors

I tried this. From what i can see after doing some attempts to connect.
First & second attempt
This is what i get after just opening the serial gateway thing and edit and sav, seems as openhab then tries to reconnect with the gateway.

third attempt
It seems like it gets connected, bu some error occurs which closes the connection again

Forth attempt actually seemed to get things going

Now to the next step.
I have a device that was just given a new address from the my sensor binding. I restarted the sensor and waited to see it in the inbox (this is something that i have seen working occasionally( sometimes it gets in there sometimes it don't. I added the device manually and it seems to work. How ever my links dont work

[TimO]

@Denke: At the first and the second attempt the gnu.io library is not able to establish a connection to the COM port. As "getPortIdentifier()" is mentioned it is possible that there is a correlation with the bug mentioned earlier in this thread. The OH developers need to update this library soon!

At the third attempt the binding does not get an answer on the I_VERSION check and therefore stops its initialization. Try skipStartupCheck=true Wiki to avoid this.

According to the discovery with PaperUI:

I must admit I have not worked with it for a long time. The OH core team has announced some big changes/improvements in the PaperUI and I've postponed my tests for after the release of this changes.

[avinaz]

Is any bodoy having high CPU load with this binding? My setup is: Openhab 2.0, running on a Pi3, with Java SDK Oracle. Openhab is running +100% CPU all the time. Here is the output of top command:

top - 19:54:33 up  9:19,  1 user,  load average: 0.98, 1.01, 1.03
Tasks: 153 total,   1 running, 152 sleeping,   0 stopped,   0 zombie
%Cpu(s): 21.4 us,  4.2 sy,  0.0 ni, 74.4 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem :   948056 total,   112832 free,   325232 used,   509992 buff/cache
KiB Swap:        0 total,        0 free,        0 used.   573692 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 3919 root      20   0  455068 180668  14280 S 101.3 19.1 547:33.46 java
28144 root      20   0    8436   2840   2280 R   0.7  0.3   0:06.30 top
  368 root      20   0    1448     88     16 S   0.3  0.0   0:31.75 rngd

If I look all the threats with command

ps -Lp 3919

I can see one that is eating too much CPU:

 3919  4226 ?        08:25:13 java

and looking at this one in the output of a thread dump: (4226 DEC = 1082 HEX)

Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: "pool-41-thread-1" #273 prio=5 os_prio=0 tid=0x62addc00 **nid=0x1082** runnable [0x5d6be000]
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]:    java.lang.Thread.State: RUNNABLE
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at gnu.io.RXTXPort.nativeavailable(Native Method)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at gnu.io.RXTXPort$SerialInputStream.available(RXTXPort.java:1568)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011- locked <0x6afb81f8> (a gnu.io.RXTXPort$SerialInputStream)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at sun.nio.cs.StreamDecoder.inReady(StreamDecoder.java:363)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at sun.nio.cs.StreamDecoder.implReady(StreamDecoder.java:371)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at sun.nio.cs.StreamDecoder.ready(StreamDecoder.java:185)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011- locked <0x6b2a41e8> (a java.io.InputStreamReader)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.io.InputStreamReader.ready(InputStreamReader.java:195)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.io.BufferedReader.ready(BufferedReader.java:463)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011- locked <0x6b2a41e8> (a java.io.InputStreamReader)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at org.openhab.binding.mysensors.protocol.MySensorsReader.run(MySensorsReader.java:50)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.util.concurrent.FutureTask.run(FutureTask.java:266)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Jun  1 19:30:31 avinaz-pi3 start.sh[3822]: #011at java.lang.Thread.run(Thread.java:745)

You can see that is related to org.openhab.binding.mysensors.protocol.MySensorsReader.run(MySensorsReader.java:50)

Any ideas?

[TimO]

@avinaz : After a second thought I now have an idea!

With the last commit I changed line 50 in MySensorsReader.java due to an exception I got after upgrading ubuntu/java and OH2.
The binding (old version) was still unchanged.

I need to look into this. Maybe @andreacioni has an idea?

[avinaz]

@TimO I would say at a glance, that the thread is continuously reading the Serial port, with out a break, so this must be very CPU consuming?