openHAB 2.2 binding MQTT support

[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.

[MasMat]

Hi everyone. Since my last I reinstalled everything. I went back to Raspbian Jessie to get Mosquitto working properly. Full reinstall of MySensors mqtt gw and Openhab2 and binding.
I have one sensor built that will not connect to the gw and I seem to be having problems on the gw as well.

Quick specs: Rpi W, jessie, nrf24.
I'm pretty new to Rpi as gateway, so I'm having little difficulty with finding debug-logs etc as well.

Here's what my configuration was:
./configure --my-transport=nrf24 --my-gateway=mqtt --my-controller-ip-address=127.0.0.1 --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=XXXX --my-mqtt-password=YYYYY --my-signing=password --my-signing-password=123456

/var/log/openhab2/openhab.log
2018-02-19 16:56:15.280 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto' to 'tcp://127.0.0.1:1883' with clientid paho108561372416048 and file store '/var/lib/openhab2/tmp/mosquitto'
2018-02-19 16:56:15.406 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto' to 'tcp://127.0.0.1:1883' with clientid paho108561583416206 and file store '/var/lib/openhab2/tmp/mosquitto'
......keeps repeating

/var/log/mosquitto/mosquitto.log
1519052215: Socket error on client <unknown>, disconnecting.
1519052215: New connection from 127.0.0.1 on port 1883.
1519052215: Socket error on client <unknown>, disconnecting.
1519052225: New connection from 127.0.0.1 on port 1883.
....keeps repeating

systemctl status mysgw.service
Feb 18 10:27:44 GwMqOH2 mysgw[359]: connect: Connection refused
Feb 18 10:27:44 GwMqOH2 mysgw[359]: failed to connect
...repeating

when I run mysgw -d:
mysgw: Starting gateway...
mysgw: Protocol version - 2.2.1-alpha
mysgw: MCO:BGN:INIT GW,CP=RNNGLSQX,VER=2.2.1-alpha
mysgw: TSF:LRT:OK
mysgw: TSM:INIT
mysgw: TSF:WUR:MS=0
mysgw: TSM:INIT:TSP OK
mysgw: TSM:INIT:GW MODE
mysgw: TSM:READY:ID=0,PAR=0,DIS=0
mysgw: MCO:REG:NOT NEEDED
mysgw: MCO:BGN:STP
mysgw: MCO:BGN:INIT OK,TSP=1
mysgw: GWT:RMQ:MQTT RECONNECT
mysgw: connected to 127.0.0.1
mysgw: GWT:RMQ:MQTT CONNECTED
mysgw: GWT:TPS:TOPIC=mysensors-out/0/255/0/0/18,MSG SENT

Any ideas? Where should I start?
Sorry for flooding, the code-block is not working for some reason....

[jjk]

@TimO after installing a (simple) sketch on a new node with the mysensors 2.2 library, I noticed frequent exceptions in the openhab logfile. It took me a while to figure out why, but it seems the issue is linked to new messages the ne mysensors library is sending in relation to smartsleep (type 32 and 33). I was able to reproduce the exceptions with manually generated mqtt messages. Below is the openhab log filtered for MySensorsMQTT

2018-02-21 13:43:23.232 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:43:23.478 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - MQTT message received. Topic: mysgw-out/151/4/1/0/0, Message: 2.4
2018-02-21 13:43:23.480 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Message topic part: 151/4/1/0/0
2018-02-21 13:43:23.481 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Converted MQTT message to MySensors Serial format. Sending on to bridge: 151;4;1;0;0;2.4
2018-02-21 13:43:23.665 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - MQTT message received. Topic: mysgw-out/151/3/1/0/4, Message: 1013
2018-02-21 13:43:23.666 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Message topic part: 151/3/1/0/4
2018-02-21 13:43:23.668 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Converted MQTT message to MySensors Serial format. Sending on to bridge: 151;3;1;0;4;1013
2018-02-21 13:43:28.499 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - MQTT message received. Topic: mysgw-out/151/255/3/0/22, Message: 13830390
2018-02-21 13:43:28.501 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Message topic part: 151/255/3/0/22
2018-02-21 13:43:28.503 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Converted MQTT message to MySensors Serial format. Sending on to bridge: 151;255;3;0;22;13830390
2018-02-21 13:43:33.234 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:43:43.236 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:43:53.238 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:44:03.240 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:44:13.242 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:44:23.244 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped
2018-02-21 13:44:23.579 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - MQTT message received. Topic: mysgw-out/43/255/3/0/33, Message: 300000
2018-02-21 13:44:23.581 [DEBUG] [rotocol.mqtt.MySensorsMqttConnection] - Message topic part: 43/255/3/0/33
2018-02-21 13:44:23.589 [ERROR] [rotocol.mqtt.MySensorsMqttConnection] - MQTT connection offline - {}
	at org.openhab.binding.mysensors.internal.protocol.mqtt.MySensorsMqttConnection$MySensorsMqttSubscriber.processMessage(MySensorsMqttConnection.java:140) ~[?:?]
2018-02-21 13:44:33.247 [TRACE] [rotocol.mqtt.MySensorsMqttConnection] - Bridge is connected, connection skipped

Currently, the only workaround seems to be to avoid smartsleep or compile the nodes with the 2.1.1 library.

[Guillermo Schimmel]

@timo Re: openHAB 2.2 binding MQTT support

Hi @TimO. I'm lost. Should I install

http://www.oberfoell.com/openhab2/org.openhab.binding.mysensors-2.2.0-mqtt.jar

or the 2.3.0-SNAPSHOT?

I'm using mqtt gateway.

It doesn't seem to startup with either one.

Thanks!

[TimO]

@guillermo-schimmel Don't use the old jar.
Use the Eclipse marketplace to install the binding or use the one linked in the wiki. They both point to the same and current jar.

Don't forget to fulfill the dependencies either by installing the features in the karaf console or by installing the new mqtt binding and the serial binding.

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

[Guillermo Schimmel]

@timo Thank you very much. I don't now how to use the marketplace, will research right now.

I have followed your instructions, but you link to the 2.3.0-SNAPSHOT. Perhaps you would like to correct that.

Thanks again