Mysensors Binding - strange behaviour

hExPY · October 24, 2017, 9:12pm

Hey guys, i’ve been wondering if anyone know whats the problem with my configuration?

I have a soundbar which uses RC6 IR Codes (the one with the Toggle bit) in lenght of 20 bit. As soon as i send the IR Code without the toggle bit, i receive this warning.

2017-10-25 10:41:11.676 [WARN ] [rsAbstractConnection$MySensorsReader] - Exception on reading from connection
java.text.ParseException: class java.text.ParseException : Message length is not > 4
	at org.openhab.binding.mysensors.internal.protocol.message.MySensorsMessage.parse(MySensorsMessage.java:336) [216:org.openhab.binding.mysensors:2.2.0.201710190834]
	at org.openhab.binding.mysensors.internal.protocol.MySensorsAbstractConnection$MySensorsReader.run(MySensorsAbstractConnection.java:345) [216:org.openhab.binding.mysensors:2.2.0.201710190834]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]

Heres my debug log

2017-10-25 10:51:54.103 [ome.event.ItemCommandEvent] - Item 'Home_Mysensors_WZ_Soundbar_Generic_Control' received command MS_WZ_SOUNDBAR_POWER
==> /var/log/openhab2/openhab.log <==
2017-10-25 10:51:54.130 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 20 found in gateway
2017-10-25 10:51:54.135 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 found in node 20
2017-10-25 10:51:54.141 [DEBUG] [rsAbstractConnection$MySensorsWriter] - Sending to MySensors: 20;1;1;0;32;4,1100C,20
==> /var/log/openhab2/events.log <==
2017-10-25 10:51:54.144 [ome.event.ItemCommandEvent] - Item 'Home_Mysensors_WZ_Soundbar_Control' received command 4,1100C,20
2017-10-25 10:51:54.157 [vent.ItemStateChangedEvent] - Home_Mysensors_WZ_Soundbar_Control changed from 4,100C,20 to 4,1100C,20
==> /var/log/openhab2/openhab.log <==
2017-10-25 10:51:54.165 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;0;3;0;9;send: 0-0-20-20 s=1,c=1,t=32,pt=0,l=10,sg=0,st=ok:4,1100C,2
==> /var/log/openhab2/events.log <==
2017-10-25 10:51:54.168 [ome.event.ItemCommandEvent] - Item 'Home_Mysensors_WZ_Soundbar_Control_Switch' received command OFF
2017-10-25 10:51:54.174 [vent.ItemStateChangedEvent] - Home_Mysensors_WZ_Soundbar_Control_Switch changed from ON to OFF
2017-10-25 10:52:27.995 [ome.event.ItemCommandEvent] - Item 'Home_Mysensors_WZ_Soundbar_Generic_Control' received command MS_WZ_SOUNDBAR_VOL_UP
2017-10-25 10:52:28.005 [vent.ItemStateChangedEvent] - Home_Mysensors_WZ_Soundbar_Generic_Control changed from MS_WZ_SOUNDBAR_POWER to MS_WZ_SOUNDBAR_VOL_UP
==> /var/log/openhab2/openhab.log <==
2017-10-25 10:52:28.027 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Node 20 found in gateway
2017-10-25 10:52:28.031 [DEBUG] [rs.internal.gateway.MySensorsGateway] - Child 1 found in node 20
2017-10-25 10:52:28.035 [DEBUG] [rsAbstractConnection$MySensorsWriter] - Sending to MySensors: 20;1;1;0;32;4,1010,20
==> /var/log/openhab2/events.log <==
2017-10-25 10:52:28.042 [ome.event.ItemCommandEvent] - Item 'Home_Mysensors_WZ_Soundbar_Control' received command 4,1010,20
2017-10-25 10:52:28.047 [vent.ItemStateChangedEvent] - Home_Mysensors_WZ_Soundbar_Control changed from 4,1100C,20 to 4,1010,20
==> /var/log/openhab2/openhab.log <==
2017-10-25 10:52:28.055 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 0;0;3;0;9;send: 0-0-20-20 s=1,c=1,t=32,pt=0,l=9,sg=0,st=ok:4,1010,20
2017-10-25 10:52:28.058 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 
2017-10-25 10:52:28.061 [WARN ] [rsAbstractConnection$MySensorsReader] - Exception on reading from connection
java.text.ParseException: class java.text.ParseException : Message length is not > 4
	at org.openhab.binding.mysensors.internal.protocol.message.MySensorsMessage.parse(MySensorsMessage.java:336) [216:org.openhab.binding.mysensors:2.2.0.201710190834]
	at org.openhab.binding.mysensors.internal.protocol.MySensorsAbstractConnection$MySensorsReader.run(MySensorsAbstractConnection.java:345) [216:org.openhab.binding.mysensors:2.2.0.201710190834]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
==> /var/log/openhab2/events.log <==
2017-10-25 10:52:28.066 [vent.ItemStateChangedEvent] - Home_Mysensors_WZ_Soundbar_Control_Switch changed from OFF to ON
2017-10-25 10:52:28.070 [ome.event.ItemCommandEvent] - Item 'Home_Mysensors_WZ_Soundbar_Control_Switch' received command ON

The Item Home_Mysensors_WZ_Soundbar_Control_Switch represents my toggle bit.

Sometimes the controller is disconnecting: (Wasnt able to get any debug lof from it):

2017-10-25 10:41:16.803 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_20_1' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2017-10-25 10:41:16.813 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_10_1' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2017-10-25 10:41:16.828 [hingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from ONLINE to OFFLINE
2017-10-25 10:41:16.840 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_20_1' changed from OFFLINE (BRIDGE_OFFLINE) to OFFLINE
2017-10-25 10:41:16.846 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_10_1' changed from OFFLINE (BRIDGE_OFFLINE) to OFFLINE
2017-10-25 10:41:16.851 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_20_1' changed from OFFLINE (COMMUNICATION_ERROR) to OFFLINE (BRIDGE_OFFLINE)
2017-10-25 10:41:16.861 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_10_1' changed from OFFLINE (COMMUNICATION_ERROR) to OFFLINE (BRIDGE_OFFLINE)
2017-10-25 10:41:19.887 [hingStatusInfoChangedEvent] - 'mysensors:bridge-ser:gateway' changed from OFFLINE to ONLINE
2017-10-25 10:41:19.896 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_20_1' changed from OFFLINE to ONLINE
2017-10-25 10:41:19.905 [hingStatusInfoChangedEvent] - 'mysensors:ir:gateway:ir_10_1' changed from OFFLINE to ONLINE

Can you guys help me out or tell me how to fix it?

Kind regards,
EDIT #1: Added Full stacktrace thanks @namraccr
EDIT #2: @namraccr you are totally right. sorry about it.
EDIT #3: added More detailed description

namraccr · October 25, 2017, 12:01am

You should include the rest of the log message/stack trace.

namraccr · October 25, 2017, 12:21am

This is a little weird. The error now appears different from the original. The original appeared to have been coming from the mysensors addon, while this one appears to show the addon is failing to load.

But perhaps I’m not remembering the original correctly.

hExPY · October 25, 2017, 4:41pm

Do you need any further information?

Sorry for the confusion.

namraccr · October 25, 2017, 11:47pm

So much better

It appears this is not a binding that officially exists. I did find a PR for it, but it appears the code you’re using is not the same as in that PR. So have you made additional modification to the code yourself?

If you use the unmodified code instead, do you get the same result?

hExPY · October 26, 2017, 7:24am

Hi

I don’t use a self-modified version of the binding. It’s the one installed from the market.
Openhab Version:

ii  openhab2                       2.2.0~20171024193001-1           all          openhab2
ii  openhab2-addons                2.2.0~20171024193001-1           all          openhab2-addons

Mysensors Binding Version:

216 │ Active   │  80 │ 2.2.0.201710190834     │ MySensors Binding

Gonna try out downloading the latest mysensors Binding and put it into the addons directory.
Tried out but nothing changed at all.

Thanks in advance for helping.

Edit #1: tried manually putting the addon in the directory.
Edit #2: Dont know if it cares but i also receive the following warnings everytime the bundle is restarted (ofc also when openhab restarted)

10:25:16.557 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR1
10:25:16.557 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR1
10:25:16.562 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR2
10:25:16.567 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR3
10:25:16.571 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR4
10:25:16.574 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR5
10:25:16.573 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR2
10:25:16.581 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR3
10:25:16.587 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR4
10:25:16.592 [WARN ] [ernal.sensors.child.MySensorsChildSIr] - Overwrite variable: V_VAR5

hExPY · November 4, 2017, 3:08pm

Hi @namraccr,

after updating MySensors to Version 2.1 from 1.4 there are no more errors.
Thanks for helping out.

Kind regards,