MQTT binding doesn't start

olg28 · July 16, 2017, 11:31am

Dear all,

I have Mosquitto and OpenHab 2 running on a Debian 9 virtual machine.
The mosquitto instance works fine, I can send messages in a topic from an Arduino plugged on the LAN.
My problem is the MQTT service of OpenHab, it never starts and failed on timed out.

mqtt.cfg :

mosquitto.url=tcp://192.168.1.120:1883
mosquitto.clientId=OpenHab
mosquitto.qos=0

openhab.log :

2017-07-16 11:20:06.732 [INFO ] [thome.core.internal.I18nProviderImpl] - Locale set to fr_FR, Location set to null
2017-07-16 11:20:12.349 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'FirstTry.items'
2017-07-16 11:20:14.252 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'FirstTry.sitemap'
2017-07-16 11:20:15.284 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.120:8080
2017-07-16 11:20:15.284 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.120:8443
2017-07-16 11:20:15.803 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2017-07-16 11:20:15.865 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2017-07-16 11:20:15.924 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2017-07-16 11:20:16.016 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2017-07-16 11:20:16.018 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'
2017-07-16 11:36:36.879 [ERROR] [o.client.mqttv3.internal.ClientState] - OpenHab: Timed out as no write activity, keepAlive=60 000 lastOutboundActivity=1 500 197 416 094 lastInboundActivity=1 500 197 416 094 time=1 500 197 796 877 lastPing=1 500 197 416 094
2017-07-16 11:36:36.886 [ERROR] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to broker was lost
Timed out while waiting to write messages to the server (32002)
	at org.eclipse.paho.client.mqttv3.internal.ExceptionHelper.createMqttException(ExceptionHelper.java:31)[183:org.openhab.io.transport.mqtt:1.10.0]
	at org.eclipse.paho.client.mqttv3.internal.ClientState.checkForActivity(ClientState.java:672)[183:org.openhab.io.transport.mqtt:1.10.0]
	at org.eclipse.paho.client.mqttv3.internal.ClientComms.checkForActivity(ClientComms.java:732)[183:org.openhab.io.transport.mqtt:1.10.0]
	at org.eclipse.paho.client.mqttv3.internal.ClientComms.checkForActivity(ClientComms.java:718)[183:org.openhab.io.transport.mqtt:1.10.0]
	at org.eclipse.paho.client.mqttv3.TimerPingSender$PingTask.run(TimerPingSender.java:77)[183:org.openhab.io.transport.mqtt:1.10.0]
	at java.util.TimerThread.mainLoop(Timer.java:555)[:1.8.0_131]
	at java.util.TimerThread.run(Timer.java:505)[:1.8.0_131]
2017-07-16 11:36:36.890 [ERROR] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to 'mosquitto' was lost: Timed out while waiting to write messages to the server : ReasonCode 32002 : Cause : Unknown
2017-07-16 11:36:36.891 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting connection helper to periodically try restore connection to broker 'mosquitto'
2017-07-16 11:36:46.897 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'

I don’t know what to do … any help ?

@+, Olivier

Nicholas_Waterton · July 16, 2017, 11:51pm

I am also having problems with mqtt after upgrading to Openhab 2.1 (along with many, many other issues).

mosuitto is working fine, but I see no evidence of OH2 even trying to connect to the broker in the mosquitto log.

I have mqttitude configured also, but not event-bus.

this is my log output:

2017-07-16 19:44:25.404 [DEBUG] [org.openhab.action.mqtt             ] - BundleEvent STARTING - org.openhab.action.mqtt
2017-07-16 19:44:25.407 [DEBUG] [b.action.mqtt.internal.MqttActivator] - Mqtt action has been started.
2017-07-16 19:44:25.407 [DEBUG] [org.openhab.action.mqtt             ] - BundleEvent STARTED - org.openhab.action.mqtt
2017-07-16 19:44:25.407 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.openhab.action.mqtt
2017-07-16 19:44:25.407 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.action.mqtt
2017-07-16 19:44:25.512 [DEBUG] [org.openhab.binding.mqtt            ] - BundleEvent STARTING - org.openhab.binding.mqtt
2017-07-16 19:44:25.513 [DEBUG] [.binding.mqtt.internal.MqttActivator] - MQTT binding has been started.
2017-07-16 19:44:25.513 [DEBUG] [org.openhab.binding.mqtt            ] - BundleEvent STARTED - org.openhab.binding.mqtt
2017-07-16 19:44:25.514 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.openhab.binding.mqtt
2017-07-16 19:44:25.514 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.binding.mqtt
2017-07-16 19:44:25.518 [DEBUG] [org.openhab.binding.mqttitude       ] - BundleEvent STARTING - org.openhab.binding.mqttitude
2017-07-16 19:44:25.519 [DEBUG] [qttitude.internal.MqttitudeActivator] - Mqttitude binding has been started.
2017-07-16 19:44:25.519 [DEBUG] [org.openhab.binding.mqttitude       ] - BundleEvent STARTED - org.openhab.binding.mqttitude
2017-07-16 19:44:25.519 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.openhab.binding.mqttitude
2017-07-16 19:44:25.520 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.binding.mqttitude
2017-07-16 19:44:25.524 [DEBUG] [org.openhab.binding.mqttitude       ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.mqttitude.MqttitudeBindingProvider}={component.name=org.openhab.binding.mqttitude.genericbindingprovider, component.id=214, service.id=335, service.bundleid=218, service.scope=bundle} - org.openhab.binding.mqttitude
2017-07-16 19:44:26.727 [DEBUG] [org.openhab.io.transport.mqtt       ] - BundleEvent STARTING - org.openhab.io.transport.mqtt
2017-07-16 19:44:26.729 [DEBUG] [org.openhab.io.transport.mqtt       ] - ServiceEvent REGISTERED - {org.openhab.io.transport.mqtt.MqttService, org.osgi.service.cm.ManagedService}={service.pid=org.openhab.mqtt, component.name=MQTT Connection Service, component.id=235, service.id=373, service.bundleid=227, service.scope=bundle} - org.openhab.io.transport.mqtt
2017-07-16 19:44:26.730 [DEBUG] [org.openhab.binding.mqttitude       ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.osgi.service.cm.ManagedService}={event.topics=openhab/command/*, service.pid=org.openhab.mqttitude, component.name=org.openhab.binding.mqttitude, component.id=213, service.id=374, service.bundleid=218, service.scope=bundle} - org.openhab.binding.mqttitude
2017-07-16 19:44:26.733 [DEBUG] [penhab.io.transport.mqtt.MqttService] - Starting MQTT Service...
2017-07-16 19:44:26.734 [DEBUG] [.mqttitude.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/Fran/iPhone/event (on proliant)
2017-07-16 19:44:26.736 [DEBUG] [.mqttitude.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/Nick/iPhone/event (on proliant)
2017-07-16 19:44:26.736 [DEBUG] [.mqttitude.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/Jill/iPhone/event (on proliant)
2017-07-16 19:44:26.736 [DEBUG] [.mqttitude.internal.MqttitudeBinding] - Activating Mqttitude binding
2017-07-16 19:44:26.737 [DEBUG] [org.openhab.binding.mqtt            ] - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.mqtt.MqttBindingProvider}={component.name=org.openhab.binding.mqtt.genericbindingprovider, component.id=210, service.id=375, service.bundleid=217, service.scope=bundle} - org.openhab.binding.mqtt
2017-07-16 19:44:26.737 [DEBUG] [org.openhab.binding.mqtt            ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler}={event.topics=openhab/*, component.name=org.openhab.binding.mqtt.MqttItemBinding, component.id=212, service.id=376, service.bundleid=217, service.scope=bundle} - org.openhab.binding.mqtt
2017-07-16 19:44:26.741 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'basementOutlet' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.742 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1IRAmbientTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.742 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1HumidityTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.742 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1BTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.743 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1IRTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.743 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1Humidity' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.743 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1Barometer' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.743 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1Lux' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.743 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1BatteryVolt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1Battery' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag1LastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2IRAmbientTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2HumidityTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2BTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2IRTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.744 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2Humidity' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2Barometer' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2Lux' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2BatteryVolt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2Battery' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag2LastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3IRAmbientTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3HumidityTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3BTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.745 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3IRTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3Humidity' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3Barometer' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3Lux' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3BatteryVolt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3Battery' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag3LastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4IRAmbientTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.746 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4HumidityTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4BTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4IRTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4Humidity' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4Barometer' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4Lux' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4BatteryVolt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4Battery' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.747 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag4LastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.748 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5IRAmbientTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.748 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5HumidityTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.748 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5BTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.748 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5IRTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.749 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5Humidity' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.749 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5Barometer' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.749 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5Lux' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.749 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5BatteryVolt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.750 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5Battery' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.750 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag5LastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.750 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6IRAmbientTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.750 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6HumidityTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.751 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6BTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.751 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6IRTemp' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.751 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6Humidity' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.751 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6Barometer' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.752 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6Lux' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.752 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6BatteryVolt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.752 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6Battery' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.752 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'sensortag6LastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.753 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'NickEventLastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.754 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'Nick_PhoneLastEvent' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.754 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'NickPhoneBatt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.754 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'Location_Nick_Phone' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.754 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'NickLocAcc' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.755 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'NickLocLastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.756 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'NickRequestLocation' : 0 subscribers, 1 publishers
2017-07-16 19:44:26.756 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'JillEventLastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.756 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'Jill_PhoneLastEvent' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.756 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'JillPhoneBatt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.757 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'Location_Jill_Phone' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.759 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'JillLocAcc' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.759 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'JillLocLastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.759 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'JillRequestLocation' : 0 subscribers, 1 publishers
2017-07-16 19:44:26.759 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'FranEventLastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.759 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'Fran_PhoneLastEvent' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.760 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'FranPhoneBatt' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.760 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'Location_Fran_Phone' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.760 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'FranLocAcc' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.760 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'FranLocLastUpdate' : 1 subscribers, 0 publishers
2017-07-16 19:44:26.760 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'FranRequestLocation' : 0 subscribers, 1 publishers
2017-07-16 19:44:26.761 [DEBUG] [org.openhab.binding.mqtt            ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.osgi.service.cm.ManagedService}={event.topics=openhab/*, service.pid=org.openhab.mqtt-eventbus, component.name=org.openhab.binding.mqtt.eventbus, component.id=211, service.id=378, service.bundleid=217, service.scope=bundle} - org.openhab.binding.mqtt
2017-07-16 19:44:26.767 [DEBUG] [ng.mqtt.internal.MqttEventBusBinding] - MQTT: Activating event bus binding.
2017-07-16 19:44:26.768 [DEBUG] [ng.mqtt.internal.MqttEventBusBinding] - Initializing MQTT Event Bus Binding
2017-07-16 19:44:26.769 [DEBUG] [ng.mqtt.internal.MqttEventBusBinding] - No broker name configured for MQTT EventBusBinding
2017-07-16 19:44:26.769 [DEBUG] [org.openhab.action.mqtt             ] - ServiceEvent REGISTERED - {org.openhab.core.scriptengine.action.ActionService, org.osgi.service.cm.ManagedService}={service.pid=org.openhab.mqtt, component.name=org.openhab.action.mqtt.action, component.id=197, service.id=379, service.bundleid=208, service.scope=bundle} - org.openhab.action.mqtt
2017-07-16 19:44:26.772 [DEBUG] [org.openhab.io.transport.mqtt       ] - BundleEvent STARTED - org.openhab.io.transport.mqtt
2017-07-16 19:44:26.772 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - Bundle Considered for SPI providers: org.openhab.io.transport.mqtt
2017-07-16 19:44:26.772 [INFO ] [g.apache.aries.spifly.dynamic.bundle] - No 'SPI-Provider' Manifest header. Skipping bundle: org.openhab.io.transport.mqtt

Any idea why mqtt just doesn’t work? I did notice that the Wiki says that user and pwd are required 9and I don’t use them), but I have tried entering bogus values, and nothing in the mosquitto log.

This was working fine, now it (and the rest of OH 2.1) is broken.

Any suggestions would be appreciated.

Nicholas_Waterton · July 16, 2017, 11:54pm

OK, removed the mqtt action (which I didn’t use), and event-bus.cfg (also not used) and mqtt finally starts up!

olg28 · July 17, 2017, 5:52am

Hello,

My initial problem is still open …

@+, Olivier

AndyW · July 17, 2017, 6:54am

Hello,
I had the same problem after the upgrade.
My Mosquitto Server simply did not run.

I have in the config the mosquitto server reinstalled and then ran it again correctly, also at a reboot.

Andy

olg28 · July 17, 2017, 11:20am

Please don’t flood my post … your problem is not the same than mine, my Mosquitto server works fine. My Arduinos can connect the mosquitto server and post information in topics.
Take a look at my initial message and we can see that Openhab turn in loop without be able to initialize the connection.

@+, Olivier

Nicholas_Waterton · July 17, 2017, 11:30am

@olg28, do you have the mqtt action loaded? or event-bus.cfg defined? When I removed these, my mqtt finally started.

I did also find that any errors in your mqtt configuration file will stop all of your mqtt configs from working - and there are no error messages.

I had to go through my entire mqtt.items file line by line, copying it into a new (mqtt_test.items) file, until the new mqtt_items.items file stopped mqtt working.

I found the error finally, it was this:

Switch  DIRECTSRed_LEDS "Red" (gDIRECT_LED) {mqtt=">[proliant:/LED_Pixel_Controller_slave/red_percent:command:ON:100],>[proliant:/LED_Pixel_Controller_slave/red_percent:command:OFF:0],<[proliant:LED_Controller/slave/red:state:MAP(switchFromMqtt.map)]",}

You see the error, right? this breaks all of your mqtt definitions (if you can’t see it, it’s the “,” before the “}” . I removed that, and mqtt started working.

NCO · July 17, 2017, 1:15pm

and stopped and started them step by step one after the other (after each restart I tried to get the update of mosquitto into OH).

Just after restarting the mqtt transport stuff it started working again just fine.
I will try to remove the action binding and will see if this happens again.

olg28 · July 17, 2017, 7:04pm

@Nicholas_Waterton
I’ve made a try by removing mqtt details of my items, I restarted everything many times and it still doesn’t work. I don’t understand anything …

@+, Olivier

Nicholas_Waterton · July 17, 2017, 7:21pm

I felt the same with V 2.1. I just spent a day getting a previously working 2.0 set up back in operation. I don’t know what precisely got mqtt working again, I tried so many things, but the new “kill everything with no error messages” policy in 2.1 makes it difficult to debug problems.

I moved everything in my mqtt.items file to mqtt.items.disabled, then put one item back in mqtt.items. check the syntax carefully! I have found so many missing or duplicated or wrong brackets in the last day.

Then I futz with OH, delete the cache and tmp directories, remove mqtt.config (in config, not the mqtt.cfg file!), restart, and watch the events log to see if my mqtt event starts showing up.

Once you have one mqtt event showing, you can add the rest of the items back one at a time, until the mqtt events stop showing - that is an item you have to fix.

Sounds torturous, but it’s the only way to debug OH2 now.

olg28 · July 18, 2017, 5:28am

Actually, I have a stitemaps with only 1 item without any mqtt details (can’t be more basic…) and still the time out…

@+ Olivier

olg28 · July 20, 2017, 5:07am

Little progress …
I’ve configure MQTT event-bus and now I can send and receive data.
But still not working with binding details inside items…

@+, Olivier

Dim · July 20, 2017, 5:40am

in this case, you need to double check the item syntax. Can you post here the items to check them?