openHAB 2.2 binding MQTT support

TimO

Is there a log entry in OpenHAB that looks like this?

[DEBUG] [.io.transport.mqtt.MqttService:155  ] - Starting MQTT Service...
[INFO ] [.i.t.mqtt.MqttBrokerConnection:576  ] - Starting MQTT broker connection 'mosquitto' to 'tcp://192.168.2.3:1883' with clientid paho6110733874326 and file store '/tmp/mosquitto'
[DEBUG] [.io.transport.mqtt.MqttService:155  ] - Starting MQTT Service...
[INFO ] [.i.t.mqtt.MqttBrokerConnection:576  ] - Starting MQTT broker connection 'mosquitto' to 'tcp://192.168.2.3:1883' with clientid paho6110762725063 and file store '/tmp/mosquitto'

Depending on your log level there only may be the INFO line.

cgrf

@TimO

I have this INFO line, as included in my first post, that looks similar but not quite the same:

2018-01-09 15:45:29.711 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'ineluki'

The four lines from my first post are actually all lines I have in that log after the UI start-up messages.

TimO

@cgrf said in openHAB 2.2 binding MQTT support:

Starting MQTT broker connection

You're using the mqtt1 (openhab1-addon) to connect to the broker. The OpenHAB2 binding is based on the current (/upcoming) mqtt-transport implementation of ESH.

My guess: the file org.eclipse.smarthome.mqtt.cfg is missing in /etc/openhab2/services and there only is a mqtt.cfg file. Just copy the mqtt.cfg file to org.eclipse.smarthome.mqtt.cfg (Same content, different name, different use).

mqtt.cfg: mqtt1 binding, mqtt-transport, owntracks ...

org.eclipse.smarthome.mqtt.cfg: ESH-MQTT and I'm only aware of my binding using it yet. But there are a few upcoming (mqtt generic, mqtt2 binding ..)

cgrf

@timo said in openHAB 2.2 binding MQTT support:

My guess: the file org.eclipse.smarthome.mqtt.cfg is missing

Excellent guess, that was my problem! My gateway is "online" now. It would have taken me forever to figure that out on my own, so thank you very much! (And yes, reading your first post now I realize that you said so.)

Should OpenHAB be able to discover the sensors behind the gateway? Or do I need to configure them manually?

TimO

@cgrf

Should OpenHAB be able to discover the sensors behind the gateway? Or do I need to configure them manually?

If you restart the node they should represent themself and will show up in the Inbox in PaperUI.

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.

openHAB 2.2 binding MQTT support

13

11.7k

11.2k

113.1k