openHAB 2.2 binding MQTT support

cgrf

@TimO
Ok, I've restarted the sensor multiple times now and I assume that it presents itself properly as it is discovered by other controllers (mycontroller.org, that is). But in OpenHAB's PaperUI it doesn't show up at all. There is a trace of it in the openhab.log though:

2018-01-10 09:29:39.268 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR1
2018-01-10 09:29:39.269 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR2
2018-01-10 09:29:39.277 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR3
2018-01-10 09:29:39.289 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR4
2018-01-10 09:29:39.289 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR5
2018-01-10 20:38:26.959 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR1
2018-01-10 20:38:26.980 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR2
2018-01-10 20:38:26.980 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR3
2018-01-10 20:38:26.980 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR4
2018-01-10 20:38:26.981 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR5
2018-01-10 20:38:27.084 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR1
2018-01-10 20:38:27.086 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR2
2018-01-10 20:38:27.086 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR3
2018-01-10 20:38:27.088 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR4
2018-01-10 20:38:27.089 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR5
2018-01-10 20:39:10.530 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:39:11.529 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:39:11.660 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:40:58.584 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:40:59.461 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:40:59.592 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway

While this is happening on MQTT:

gateway1-out/3/255/0/0/17 2.1.1
gateway1-out/3/255/3/0/6 0
gateway1-out/3/255/3/0/11 Combined Climate Sensor
gateway1-out/3/255/3/0/12 1.0.16
gateway1-out/3/0/0/0/7 (null)
gateway1-out/3/7/0/0/30 (null)
gateway1-out/3/10/2/0/15 (null)
gateway1-out/3/1/1/0/0 21.9
gateway1-out/3/0/1/0/1 42
gateway1-out/3/7/1/0/38 3.98
gateway1-out/3/255/3/0/0 56

Have you got another hint for me, maybe? It would be greatly appreciated.

cgrf

Unfortunately, I'm still making no progress here. In the meantime I deleted the MQTT Gateway in the Paper UI and restarted the device to see what would happen. Now I'm seeing an error in openhab.log:

2018-01-16 19:45:23.419 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection 'ineluki' to 'tcp://192.168.5.2:1883' with clientid openhab2 and file store '/openhab/userdata/tmp/ineluki'
2018-01-16 19:45:29.680 [INFO ] [.transport.mqtt.MqttBrokerConnection] - MQTT connection to 'ineluki' was lost: MqttException
2018-01-16 19:45:29.681 [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) [211: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.mqtt.MySensorsMqttConnection$MySensorsMqttSubscriber.processMessage(MySensorsMqttConnection.java:142) ~[?:?]
        at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.messageArrived(MqttBrokerConnection.java:121) ~[?:?]
        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-01-16 19:45:29.709 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to 'ineluki' every 10000ms

Does this give any clue on what's going wrong?

cgrf

Ok, now I'm seeing items in my Inbox, after I changed my org.eclipse.smarthome.mqtt.cfg from

ineluki.qos=2
ineluki.retain=true

to

#ineluki.qos=2
ineluki.retain=false

MasMat

OK, n00b questions again:

where to place the binding-jar and do I have to do something with the jar-file?
no services directory exists in /etc. Create it?
any other things to install? Fresh PaperUI-OpenHab installation so far.
My system:RpiZero/Scratch+Mosquitto.

TimO

@masmat

/usr/share/openhab2/addons/
Thank you for the hint, I've pointed to the wrong directory, it's: /etc/openhab2/services
For additional Informations please have a look at the wiki: https://github.com/tobof/openhab2-addons/wiki

TimO

@cgrf Thank you for the hint! At the moment I don't have an explanation for that behaviour.

MasMat

@timo I still cant find mqtt.cfg OR org.eclipse.smarthome.mqtt.cfg. I looked thru the Github stuff but didn't see it.

Any ideas where to locate either of these files? I assume they have more lines than those four on display in the example.
Thanks. Sorry I'm still a tool with OH2

LastSamurai

@masmat As far as I know .cfg files are only the config files fpr your installed addons and are located in the service directory (see TimO's post above). And they indeed only contain the settings you want to use, which can be 4 lines only. Depends on the addon

MasMat

@lastsamurai I kinda figured that. From the first post I understood that the MQTT binding (binding-mqtt1 - 1.11.0) did not need to be installed. mqtt.cfg -file does come from that. So far I haven't installed it, but if that's where the mqtt.cfg file should come from then I'll do that next.
Just dont want to have addon on top of addon if they're redundant.

TimO

@masmat Just create the org.eclipse.smarthome.mqtt.cfg file. It's not created automatically. mqtt.cfg is not needed for the binding.

MasMat

@timo Alright!! MQTT Gateway Online. Thanks for your patience. Hopefully this thread will help future hopefuls.
Now, I'm gonna activate some nodes and see what happens.

MasMat

Well, this joy lasted almost 24h...until I unplugged and moved the set-up.
Now Mosquitto-service wont start "Status 11/SEGV"...went nuts looking for that.
Moved Mosquitto to another machine, but now mysgw-service "failed to connect".

Any ideas why Mosquitto went status11 after reboot?
Why wont mysgw connect to another Mosquitto IP? does the port 1883 need to be configured as well?

My configure-line: --my-transport=nrf24 --my-gateway=mqtt --my-controller-ip-address=192.168.0.52 --my-mqtt-publish-topic-prefix=mysensors-out --my-mqtt-subscribe-topic-prefix=mysensors-in --my-mqtt-client-id=mygateway1 --my-rf24-irq-pin=15 --my-leds-err-pin=12 --my-leds-rx-pin=16 --my-leds-tx-pin=18 --my-mqtt-user=????? —-my-mqtt-password=???????

BenPr

@TimO The MySonsors Binding didn't find any things for me. :-/
My /etc/openhab2/services/org.eclipse.smarthome.mqtt.cfg

broker.url=tcp://localhost:1883
broker.clientId=openhabianpi
broker.user=*private*
broker.pwd=*private*

My /etc/mosquitto/mosquitto.conf

pid_file /var/run/mosquitto.pid

persistence true
persistence_location /var/lib/mosquitto/

log_dest file /var/log/mosquitto/mosquitto.log

include_dir /etc/mosquitto/conf.d

password_file /etc/mosquitto/passwd
allow_anonymous false

My /var/log/mosquitto/mosquitto.log

1516918990: mosquitto version 1.4.10 (build date Mon, 29 May 2017 13:43:29 +0100) starting
1516918990: Config loaded from /etc/mosquitto/mosquitto.conf.
1516918990: Opening ipv4 listen socket on port 1883.
1516918990: Opening ipv6 listen socket on port 1883.
1516919015: New connection from x.x.x.29 on port 1883.
1516919015: New client connected from x.x.x.29 as MQTT_Terrassen_Beleuchtung (c1, k15, u'openhabian').
1516919044: New connection from 127.0.0.1 on port 1883.
1516919044: New client connected from 127.0.0.1 as openhabianpi (c1, k60, u'openhabian').
1516920798: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.

MQTT_Terrassen_Beleuchtung is the thing to find.

My /var/log/openhab2/openhab.log

2018-01-26 00:15:23.079 [INFO ] [.internal.GenericScriptEngineFactory] - Activated scripting support for ECMAScript
2018-01-26 00:15:25.437 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-01-26 00:15:28.660 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to de_DE, Location set to 51.5032,7.0073, Time zone set to Europe/Berlin
2018-01-26 00:15:31.505 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection 'broker' to 'tcp://localhost:1883' with clientid openhabianpi and file store '/var/lib/openhab2/tmp/broker'
2018-01-26 00:15:31.642 [WARN ] [rthome.io.transport.mqtt.MqttService] - MqttBroker start failed: Persistenz wird bereits verwendet
org.eclipse.smarthome.io.transport.mqtt.MqttException: Persistenz wird bereits verwendet
        at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection.start(MqttBrokerConnection.java:572) [289:org.eclipse.smarthome.io.transport.mqtt:0.10.0.b1]
        at org.eclipse.smarthome.io.transport.mqtt.MqttService.modified(MqttService.java:145) [289:org.eclipse.smarthome.io.transport.mqtt:0.10.0.b1]
        at org.eclipse.smarthome.io.transport.mqtt.MqttService.activate(MqttService.java:157) [289:org.eclipse.smarthome.io.transport.mqtt:0.10.0.b1]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.apache.felix.scr.impl.inject.BaseMethod.invokeMethod(BaseMethod.java:229) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.inject.BaseMethod.access$500(BaseMethod.java:39) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.inject.BaseMethod$Resolved.invoke(BaseMethod.java:650) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.inject.BaseMethod.invoke(BaseMethod.java:506) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.inject.ActivateMethod.invoke(ActivateMethod.java:307) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.inject.ActivateMethod.invoke(ActivateMethod.java:299) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:298) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:109) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:906) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:879) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:823) [42:org.apache.felix.scr:2.0.12]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
        at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:496) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:619) [?:?]
        at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [15:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
        at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) [?:?]
        at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:915) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:887) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:874) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:132) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:941) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:741) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleDynamicCustomizer.addedService(DependencyManager.java:799) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleDynamicCustomizer.addedService(DependencyManager.java:743) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:127) [42:org.apache.felix.scr:2.0.12]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:915) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:887) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:874) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:132) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:941) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:741) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1012) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:968) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1215) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1136) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:945) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:881) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1167) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:127) [42:org.apache.felix.scr:2.0.12]
        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:915) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:464) [?:?]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:887) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:874) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:132) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:941) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:741) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:675) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:430) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:657) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:341) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:390) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:54) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:265) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.utils.extender.AbstractExtender.createExtension(AbstractExtender.java:254) [42:org.apache.felix.scr:2.0.12]
        at org.apache.felix.utils.extender.AbstractExtender.modifiedBundle(AbstractExtender.java:227) [42:org.apache.felix.scr:2.0.12]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [?:?]
        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [?:?]
        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [?:?]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:903) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:156) [?:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
        at org.eclipse.osgi.container.Module.start(Module.java:467) [?:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1620) [?:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1600) [?:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1571) [?:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1514) [?:?]
        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]
Caused by: org.eclipse.paho.client.mqttv3.MqttPersistenceException: Persistenz wird bereits verwendet
        at org.eclipse.paho.client.mqttv3.persist.MqttDefaultFilePersistence.open(MqttDefaultFilePersistence.java:112) ~[?:?]
        at org.eclipse.paho.client.mqttv3.MqttAsyncClient.<init>(MqttAsyncClient.java:286) ~[?:?]
        at org.eclipse.paho.client.mqttv3.MqttAsyncClient.<init>(MqttAsyncClient.java:167) ~[?:?]
        at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection.start(MqttBrokerConnection.java:570) ~[?:?]
        ... 118 more
2018-01-26 00:15:32.456 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://x.x.x.30:8080
2018-01-26 00:15:32.465 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://x.x.x.30:8443
2018-01-26 00:15:52.506 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-01-26 00:16:01.849 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-01-26 00:16:01.999 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-01-26 00:16:02.291 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-01-26 00:16:02.816 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:broker
2018-01-26 00:16:02.819 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:topic
2018-01-26 00:16:02.822 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:message
2018-01-26 00:16:05.597 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2018-01-26 00:16:06.390 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app

Have you any idea to fix this?

jjk

This post is deleted!

jjk

Hi @TimO ,

after doing clean install of OH and the ESH mqtt binding per the original post above, the mqqt service ran properly (no errors in the debug log). After installing the mysensors binding, I start seing mysensors topics come in, but then following exception is thrown

2018-02-06 20:01:10.676 [DEBUG] [o.client.mqttv3.internal.ClientState] - paho167001634703924: received key=1 message=PUBLISH qos:1 msgId:1 retained:true dup:false topic:"mysgw-out/1/0/1/0/97" payload:[hex:33392e38 utf8:"39.8" length:4]
2018-02-06 20:01:10.676 [DEBUG] [o.client.mqttv3.internal.ClientState] - paho167001634703924: received key=1 token=org.eclipse.paho.client.mqttv3.MqttToken@e71260 message=SUBACK msgId 1 granted Qos 1
2018-02-06 20:01:10.677 [DEBUG] [client.mqttv3.internal.CommsCallback] - paho167001634703924: new msg avail, notify workAvailable
2018-02-06 20:01:10.678 [DEBUG] [o.client.mqttv3.internal.ClientState] - paho167001634703924: wait for new work or for space in the inflight window
2018-02-06 20:01:10.679 [DEBUG] [client.mqttv3.internal.CommsReceiver] - paho167001634703924: network read message
2018-02-06 20:01:10.679 [DEBUG] [client.mqttv3.internal.CommsCallback] - paho167001634703924: call messageArrived key=1 topic=mysgw-out/1/0/1/0/97
2018-02-06 20:01:10.680 [DEBUG] [o.client.mqttv3.internal.ClientState] - paho167001634703924: received bytes count=1
2018-02-06 20:01:10.681 [DEBUG] [o.client.mqttv3.internal.ClientState] - paho167001634703924: received bytes count=28
2018-02-06 20:01:10.681 [DEBUG] [client.mqttv3.internal.CommsCallback] - paho167001634703924: callback threw exception
        at org.openhab.binding.mysensors.internal.protocol.mqtt.MySensorsMqttConnection$MySensorsMqttSubscriber.processMessage(MySensorsMqttConnection.java:140) [233:org.openhab.binding.mysensors:2.2.0.201712141227]
        at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.messageArrived(MqttBrokerConnection.java:121) [232:org.eclipse.smarthome.io.transport.mqtt:0.10.0.b1]
        at org.eclipse.paho.client.mqttv3.internal.CommsCallback.handleMessage(CommsCallback.java:354) [231:org.eclipse.paho.client.mqttv3:1.0.2]
        at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:162) [231:org.eclipse.paho.client.mqttv3:1.0.2]
2018-02-06 20:01:10.683 [DEBUG] [o.client.mqttv3.internal.ClientComms] - paho167001634703924: state=DISCONNECTING

Any idea what I'm doing wrong?

UPDATE:
For what it's worth, I found the trigger for the error. In fact, the mqtt messages the binding received were (for whatever reason) retained messages of the mosquitto broker. After removing the mosquitto presistence file

sudo service mosquitto stop
sudo rm /var/lib/mosquitto/mosquitto.db
sudo service mosquitto start

it now seems to work o.k. - Hope this might help others who come across this thread.

TimO

@jjk Thank you for reporting back!

jjk

@timo, another effect I noticed is that the mysensor binding seems a bit sensitive to updates in the things and item files. I got new errors every time I added a thing to the things file or modified the items file. After rebooting OH those erros were gone and the things properly included. Stopping the mysensors binding (bundle:stop) before adding/changing things or items and restarting it afterwards works without a problem.

jogant

hi,
first I would say thanks for the binding. Generally I got it working, but I build a special sensor for my district heating counter. It has two sensors in one node, power and watermeter. The power sensor also sends messages for value types VAR1-5. Unfortunately these value seem to have a problem. I see them in the mosquitto broker but in openhab I can't see them. In the logging there are some warnings concerning these values.
Is it a known problem?

thanks and best regards
Joachim

TimO

@jogant please enable debug output with log:set DEBUG org.openhab.binding.mysensors and post the debug output here. I'll look at it.

jogant

@timo I enabled debugging and could see that all mqtt messages are received correct. I had a problem with caching through jsondb. I deleted some things and links and now everything is fine. So nothing wrong in the binding. Thanks for your helpful hint.

openHAB 2.2 binding MQTT support

20

11.7k

11.2k

113.1k