tobof / openhab-addons

The next-generation open Home Automation Bus (openHAB)
Eclipse Public License 2.0
39 stars 30 forks source link

MySensors Binding kills MQTT Connection #128

Open EtherFidelity opened 5 years ago

EtherFidelity commented 5 years ago

Enabling the binding on my network causes this to appear in the OpenHAB log. I have no idea what the problem is, only that it seems to be induced by the MySensors binding.

2018-11-24 00:50:20.835 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'localhost' with clientid paho2090127366435 and file store '/var/lib/openhab2/mqtt/localhost' 2018-11-24 00:50:20.857 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Connected to MQTT broker! 2018-11-24 00:50:21.031 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - MQTT message received. Topic: Devices/LP-Gateway/Out/10/255/3/0/32, Message: 500 2018-11-24 00:50:21.032 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Message topic part: 10/255/3/0/32 2018-11-24 00:50:21.037 [INFO ] [.transport.mqtt.MqttBrokerConnection] - MQTT connection to 'localhost' was lost: MqttException 2018-11-24 00:50:21.038 [ERROR] [rotocol.mqtt.MySensorsMqttConnection] - MQTT connection offline - {} org.eclipse.paho.client.mqttv3.MqttException: MqttException at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:176) [215:org.eclipse.paho.client.mqttv3:1.0.2] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: java.lang.NullPointerException at org.openhab.binding.mysensors.internal.protocol.message.MySensorsMessage.generateAPIString(MySensorsMessage.java:390) ~[?:?] at org.openhab.binding.mysensors.internal.protocol.mqtt.MySensorsMqttConnection$MySensorsMqttSubscriber.processMessage(MySensorsMqttConnection.java:138) ~[?:?] at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.lambda$2(MqttBrokerConnection.java:143) ~[?:?] at java.util.ArrayList.forEach(ArrayList.java:1257) ~[?:?] at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.lambda$1(MqttBrokerConnection.java:143) ~[?:?] at java.util.HashMap.forEach(HashMap.java:1289) ~[?:?] at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.messageArrived(MqttBrokerConnection.java:140) ~[?:?] at org.eclipse.paho.client.mqttv3.internal.CommsCallback.handleMessage(CommsCallback.java:354) ~[?:?] at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:162) ~[?:?] ... 1 more 2018-11-24 00:50:21.044 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to 'localhost' every 10000ms 2018-11-24 00:51:21.045 [ERROR] [rotocol.mqtt.MySensorsMqttConnection] - MQTT connection offline - Reason unknown 2018-11-24 00:51:21.049 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to 'localhost' with clientid paho2090127366435 and file store '/var/lib/openhab2/mqtt/localhost' 2018-11-24 00:51:21.071 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Connected to MQTT broker! 2018-11-24 00:51:21.233 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - MQTT message received. Topic: Devices/LP-Gateway/Out/10/255/3/0/32, Message: 500 2018-11-24 00:51:21.234 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Message topic part: 10/255/3/0/32 2018-11-24 00:51:21.238 [INFO ] [.transport.mqtt.MqttBrokerConnection] - MQTT connection to 'localhost' was lost: MqttException 2018-11-24 00:51:21.239 [ERROR] [rotocol.mqtt.MySensorsMqttConnection] - MQTT connection offline - {} org.eclipse.paho.client.mqttv3.MqttException: MqttException at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:176) [215:org.eclipse.paho.client.mqttv3:1.0.2] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: java.lang.NullPointerException at org.openhab.binding.mysensors.internal.protocol.message.MySensorsMessage.generateAPIString(MySensorsMessage.java:390) ~[?:?] at org.openhab.binding.mysensors.internal.protocol.mqtt.MySensorsMqttConnection$MySensorsMqttSubscriber.processMessage(MySensorsMqttConnection.java:138) ~[?:?] at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.lambda$2(MqttBrokerConnection.java:143) ~[?:?] at java.util.ArrayList.forEach(ArrayList.java:1257) ~[?:?] at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.lambda$1(MqttBrokerConnection.java:143) ~[?:?] at java.util.HashMap.forEach(HashMap.java:1289) ~[?:?] at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.messageArrived(MqttBrokerConnection.java:140) ~[?:?] at org.eclipse.paho.client.mqttv3.internal.CommsCallback.handleMessage(CommsCallback.java:354) ~[?:?] at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:162) ~[?:?] ... 1 more 2018-11-24 00:51:21.246 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to 'localhost' every 10000ms

Any idea what is going on? I'm stumped.

tobof commented 5 years ago

The binding is receiving a message at topic: "Devices/LP-Gateway/Out/10/255/3/0/32"

An internal message (3) with I_PRE_SLEEP_NOTIFICATION (32) with a content "500 2018-11-24 00:50:21.032 [DEBUG] "

Is this message received from a node? What is the expected behaviour? What should the binding do with it?