MQTT not working since upgrade

Chris_Walker · March 4, 2017, 2:21am

Hi,

Last weekend I upgraded from Openhab2 Beta to the current release available on openhab.org. Ever since my mqtt hasn’t been able to connect to my Mosquitto instance and I can’t work out why. Before the upgrade this was working perfectly and I haven’t changed my conf folder. As far as I’m aware, only the addons and runtime have changed. Is anyone able to decipher the following log?

Number		LivingRoomTemp			<temperature>	(Graphed)	{mqtt="<[localhost:ourhouse/livingroom/temperature:state:default]"}

2017-03-04 13:12:54.543 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (226): Starting destruction process
2017-03-04 13:12:54.543 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (226): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.544 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (226): Starting destruction process
2017-03-04 13:12:54.544 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (226): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.544 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (226): Starting destruction process
2017-03-04 13:12:54.545 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (226): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.550 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mqtt (227): Starting destruction process
2017-03-04 13:12:54.550 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mqtt (227): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.550 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mqtt (227): Starting destruction process
2017-03-04 13:12:54.551 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mqtt (227): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.551 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mqtt (227): Starting destruction process
2017-03-04 13:12:54.552 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.binding.mqtt (227): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.553 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (229): Starting destruction process
2017-03-04 13:12:54.554 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (229): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.554 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (229): Starting destruction process
2017-03-04 13:12:54.554 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (229): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.555 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (229): Starting destruction process
2017-03-04 13:12:54.555 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.action.mqtt (229): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.557 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (230): Starting destruction process
2017-03-04 13:12:54.557 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (230): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.558 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (230): Starting destruction process
2017-03-04 13:12:54.558 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (230): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.558 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (230): Starting destruction process
2017-03-04 13:12:54.559 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (230): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.561 [INFO ] [penhab.io.transport.mqtt.MqttService] - Stopping broker connection 'localhost'
2017-03-04 13:12:54.563 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (228): Starting destruction process
2017-03-04 13:12:54.563 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (228): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.563 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (228): Starting destruction process
2017-03-04 13:12:54.563 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (228): Not an extended bundle or destruction of extension already finished
2017-03-04 13:12:54.564 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (228): Starting destruction process
2017-03-04 13:12:54.564 [DEBUG] [ell.impl.action.osgi.CommandExtender] - org.openhab.io.transport.mqtt (228): Not an extended bundle or destruction of extension already finished
2017-03-04 13:13:20.077 [DEBUG] [url.mvn.internal.AetherBasedResolver] - Resolved (org.openhab.io:org.openhab.io.transport.mqtt:jar:1.9.0) as /opt/openhab2/userdata/kar/openhab-addons-2.0.0/org/openhab/io/org.openhab.io.transport.mqtt/1.9.0/org.openhab.io.transport.mqtt-1.9.0.jar
2017-03-04 13:13:20.078 [DEBUG] [url.mvn.internal.AetherBasedResolver] - Resolved (org.openhab.action:org.openhab.action.mqtt:jar:1.9.0) as /opt/openhab2/userdata/kar/openhab-addons-2.0.0/org/openhab/action/org.openhab.action.mqtt/1.9.0/org.openhab.action.mqtt-1.9.0.jar
2017-03-04 13:13:20.243 [DEBUG] [url.mvn.internal.AetherBasedResolver] - Resolved (org.eclipse.paho:org.eclipse.paho.client.mqttv3:jar:1.0.2) as /opt/openhab2/runtime/system/org/eclipse/paho/org.eclipse.paho.client.mqttv3/1.0.2/org.eclipse.paho.client.mqttv3-1.0.2.jar
2017-03-04 13:13:21.233 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.action.mqtt
2017-03-04 13:13:21.238 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.io.transport.mqtt
2017-03-04 13:13:21.261 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.action.mqtt
2017-03-04 13:13:21.293 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.io.transport.mqtt
2017-03-04 13:13:32.115 [DEBUG] [mpl.info.InfoBundleTrackerCustomizer] - Ignore incorrect info null provided by bundle org.openhab.binding.mqtt

sihui · March 4, 2017, 11:30am

It looks like the dependencies for the MQTT binding (org.openhab.io.transport.mqtt) are missing.
Also it looks like you have the MQTT actions installed. I’ve read somewhere that this can cause problems.

Log into karaf and do a bundle:list to see which bindings regarding MQTT are active:

201 | Active   |  80 | 1.10.0.201703020211   | openHAB MQTT Binding
208 | Active   |  80 | 1.10.0.201703020211   | openHAB MQTT Transport Bundle

Those two are active in my system and MQTT is working fine

I highly recommend to take a look at

especially
Replacement of mapdb by jsondb and
New folder structure

Those were breaking changes and you may end up in a new and fresh install …

Guillaume · March 4, 2017, 12:51pm

I encounter the same problem MQTT not working after upgrading to recent snapshot.

I doubt the problem is linked to the folder structure change or json db, as my config relies exclusively on files …

I am using both MQTT binding and MQQT action. Was working perfectly fine before.

Please, let me know is i can provide any information usefull to investigate the problem

Guillaume

Guillaume · March 4, 2017, 12:53pm

Uninstalling MQTT action seems to bring back online the MQTT binding. Any idea on how to have both working at the same time ?

namraccr · March 4, 2017, 1:09pm

The open ticket is #5038.

Chris_Walker · March 5, 2017, 1:41am

Thanks everyone. Removing the action worked for me too. Removing it from addons.cfg didn’t seem to be enough though. After updating addons.cfg and restarting Openhab, the mqtt action still appeared when running bundle:list.

I then used bundle:uninstall and restarted Openhab again. After doing this the mqtt bining came back to life.

Before:
226 | Active | 80 | 1.10.0.201703010201 | openHAB Mqtt Action
227 | Active | 80 | 1.9.0.201701220201 | openHAB MQTT Binding
228 | Active | 80 | 1.10.0.201703010201 | openHAB MQTT Transport Bundle

Now:
227 | Active | 80 | 1.9.0.201701220201 | openHAB MQTT Binding
228 | Active | 80 | 1.10.0.201703010201 | openHAB MQTT Transport Bundle

grizzlyjere · March 30, 2017, 3:15pm

I appear to be having the same problem - Previously working 2.0b5 install that now fails to work with MQTT.

I’ve tried to turn on logging, but oddly I’m not seeing any mention of MQTT

log:set TRACE org.openhab.binding.mqtt
log:set TRACE org.openhab.io.transport.mqtt

I’ve uninstalled the MQTT action and restarted per this thread and it didn’t help. I’m also not even seeing openhab connecting to the local Mosquitto MQTT server.

Any thoughts?