Addons.cfg file and log file errors Question

I have started reading more posts in the Community and gaining more knowledge about setting up my ESP8266 boards to work with the new MQTT 2.4. As I add more sensors to my setup, I often check the log files when I reboot. I noticed I get a lot of errors when first booting. Once everything loads up, all the sensors, weather, time reading display properly on the Basic UI screens and no more errors.

I have not made any changes to the addons.cfg file to autoload all the settings I’m using. If I did edit all the options I’m using in that file, do you think that might get rid of all the initial boot errors?

Just added my second ESP8266 with the BME280 sensor board and it’s working like a champ.

Thanks for the feedback

John Frankforther

How should we know if you don’t post the errors???

If I remember correctly, you mentioned in another post that you use PaperUI to install bindings, etc. Please be aware that you cannot mix PaperUI with the addons.cfg. If you edit the latter, you have to make all changes to this entry in the file (e.g., if you uncomment the bindings line, only the bindings mentioned in the file will be installed, and changes in PaperUI will be ignored every time you restart or safe the files addons.cfg)

As far as the errors go, I’m assuming that they are caused because all the bindings were created in the Paper UI and the bindings aren’t set up until the Paper UI is loaded. (I’m assuming here)

I have read and know that if I use the addon.cfg then only the bindings listed in there are the ones to be loaded and everything else is removed. Most of the errors in the log file have to do with MQTT. In watching the log file, I can see where the MQTT is loaded and then the errors go away. So I didn’t know if I set up the bindings in the cfg file, that may eliminate the errors, thinking it would load all those bindings before they were called in any of the screens. (Again, assuming how things work)

That’s not how it works. Once installed, the binding is installed whether or not PaperUI is present or loaded.

It won’t. But even if this were possible, as sihui said, how could we tell you one way or the other without seeing what the errors are?

@rlkoshak @sihui

Ok What if I stop OH, clear the events and openhab log files then reboot OH? This should show me what is happening when OH loads up and then I can post the log files here. Maybe then we can figure out what I have set up wrong. Would that work?

John Frankforther

Good idea :+1:

Here is my log file as I just captured it. I swear It’s like as soon as the Paper UI starts, everything starts working. Although the first line does say the MQTTBroker connection configuration is faulty.

2019-02-25 13:26:02.904 [WARN ] [.MqttBrokerConnectionServiceInstance] - MqttBroker connection configuration faulty: host : You need to provide a hostname/IP!

2019-02-25 13:26:26.719 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder

2019-02-25 13:26:29.743 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel

2019-02-25 13:26:30.082 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'America/Detroit'.

2019-02-25 13:26:30.205 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_US'.

2019-02-25 13:28:23.168 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ourhome.items'

2019-02-25 13:28:55.088 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007

2019-02-25 13:29:00.565 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ourhome.sitemap'

2019-02-25 13:29:03.764 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ourhome.things'

==> /var/log/openhab2/events.log <==

2019-02-25 13:29:09.128 [.ItemChannelLinkAddedEvent] - Link 'localCurrentWindSpeed-openweathermap:weather-and-forecast:api:local:current#wind-speed' has been added.

2019-02-25 13:29:09.187 [.ItemChannelLinkAddedEvent] - Link 'MF_Office_Humidity-mqtt:topic:a6379cde:BME280-1H' has been added.

2019-02-25 13:29:09.265 [.ItemChannelLinkAddedEvent] - Link 'localCurrentRainVolume-openweathermap:weather-and-forecast:api:local:current#rain' has been added.

2019-02-25 13:29:09.303 [.ItemChannelLinkAddedEvent] - Link 'MF_Dining_Temperature-mqtt:topic:b7afda60:DHT11' has been added.

2019-02-25 13:29:09.345 [.ItemChannelLinkAddedEvent] - Link 'MF_Office_Temperature-mqtt:topic:a6379cde:BME280T' has been added.

2019-02-25 13:29:09.385 [.ItemChannelLinkAddedEvent] - Link 'MF_Office_Light-mqtt:topic:b27a43be:OL01' has been added.

2019-02-25 13:29:09.431 [.ItemChannelLinkAddedEvent] - Link 'localCurrentSnowVolume-openweathermap:weather-and-forecast:api:local:current#snow' has been added.

2019-02-25 13:29:09.489 [.ItemChannelLinkAddedEvent] - Link 'localCurrentConditionIcon-openweathermap:weather-and-forecast:api:local:current#icon' has been added.

2019-02-25 13:29:09.510 [.ItemChannelLinkAddedEvent] - Link 'localCurrentHumidity-openweathermap:weather-and-forecast:api:local:current#humidity' has been added.

2019-02-25 13:29:09.539 [.ItemChannelLinkAddedEvent] - Link 'localLastMeasurement-openweathermap:weather-and-forecast:api:local:current#time-stamp' has been added.

2019-02-25 13:29:09.567 [.ItemChannelLinkAddedEvent] - Link 'B_Workshop_Humidity-mqtt:topic:5117baec:BME280-2H' has been added.

2019-02-25 13:29:09.611 [.ItemChannelLinkAddedEvent] - Link 'localStationName-openweathermap:weather-and-forecast:api:local:station#name' has been added.

2019-02-25 13:29:09.647 [.ItemChannelLinkAddedEvent] - Link 'B_Workshop_Temperature-mqtt:topic:5117baec:BME280-2T' has been added.

2019-02-25 13:29:09.672 [.ItemChannelLinkAddedEvent] - Link 'B_Workshop_Pressure-mqtt:topic:5117baec:BME280-2P' has been added.

2019-02-25 13:29:09.704 [.ItemChannelLinkAddedEvent] - Link 'localStationId-openweathermap:weather-and-forecast:api:local:station#id' has been added.

2019-02-25 13:29:09.721 [.ItemChannelLinkAddedEvent] - Link 'MF_Office_Pressure-mqtt:topic:a6379cde:BME280-1P' has been added.

2019-02-25 13:29:09.746 [.ItemChannelLinkAddedEvent] - Link 'Time-ntp:ntp:ourhome:dateTime' has been added.

2019-02-25 13:29:09.771 [.ItemChannelLinkAddedEvent] - Link 'localCurrentWindDirection-openweathermap:weather-and-forecast:api:local:current#wind-direction' has been added.

2019-02-25 13:29:09.809 [.ItemChannelLinkAddedEvent] - Link 'MF_Dining_Humidity-mqtt:topic:b7afda60:DHT11H' has been added.

2019-02-25 13:29:09.831 [.ItemChannelLinkAddedEvent] - Link 'localCurrentTemperature-openweathermap:weather-and-forecast:api:local:current#temperature' has been added.

2019-02-25 13:29:09.860 [.ItemChannelLinkAddedEvent] - Link 'Date-ntp:ntp:ourhome:dateTime' has been added.

2019-02-25 13:29:09.888 [.ItemChannelLinkAddedEvent] - Link 'localCurrentCondition-openweathermap:weather-and-forecast:api:local:current#condition' has been added.

2019-02-25 13:29:09.906 [.ItemChannelLinkAddedEvent] - Link 'localCurrentCloudiness-openweathermap:weather-and-forecast:api:local:current#cloudiness' has been added.

2019-02-25 13:29:09.928 [.ItemChannelLinkAddedEvent] - Link 'localCurrentPressure-openweathermap:weather-and-forecast:api:local:current#pressure' has been added.

==> /var/log/openhab2/openhab.log <==

2019-02-25 13:29:09.843 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "MF_Office_Light -> mqtt:topic:b27a43be:OL01". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:09.962 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "MF_Office_Temperature -> mqtt:topic:a6379cde:BME280T". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.007 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "MF_Office_Humidity -> mqtt:topic:a6379cde:BME280-1H". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.050 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "MF_Dining_Humidity -> mqtt:topic:b7afda60:DHT11H". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.084 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "B_Workshop_Temperature -> mqtt:topic:5117baec:BME280-2T". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.120 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "MF_Office_Pressure -> mqtt:topic:a6379cde:BME280-1P". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.184 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "B_Workshop_Pressure -> mqtt:topic:5117baec:BME280-2P". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.212 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "B_Workshop_Humidity -> mqtt:topic:5117baec:BME280-2H". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

2019-02-25 13:29:10.255 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "ItemChannelLink" with key "MF_Dining_Temperature -> mqtt:topic:b7afda60:DHT11". It exists already from provider "GenericItemChannelLinkProvider"! Failed to add a second with the same UID from provider "ManagedItemChannelLinkProvider"!

==> /var/log/openhab2/events.log <==

2019-02-25 13:29:10.310 [.ItemChannelLinkAddedEvent] - Link 'localDailyForecastTomorrowTimestamp-openweathermap:weather-and-forecast:api:local:forecastHours24#time-stamp' has been added.

2019-02-25 13:29:10.348 [.ItemChannelLinkAddedEvent] - Link 'Date-ntp:ntp:local:dateTime' has been added.

2019-02-25 13:29:10.392 [.ItemChannelLinkAddedEvent] - Link 'localDailyForecastTomorrowConditionIcon-openweathermap:weather-and-forecast:api:local:forecastHours24#icon' has been added.

2019-02-25 13:29:10.418 [.ItemChannelLinkAddedEvent] - Link 'localDailyForecastTomorrowCondition-openweathermap:weather-and-forecast:api:local:forecastHours24#condition' has been added.

2019-02-25 13:29:11.413 [hingStatusInfoChangedEvent] - 'openweathermap:weather-api:api' changed from UNINITIALIZED to INITIALIZING

2019-02-25 13:29:11.717 [hingStatusInfoChangedEvent] - 'openweathermap:weather-api:api' changed from INITIALIZING to UNKNOWN

2019-02-25 13:29:11.942 [hingStatusInfoChangedEvent] - 'openweathermap:weather-and-forecast:api:local' changed from UNINITIALIZED to INITIALIZING

2019-02-25 13:29:12.012 [hingStatusInfoChangedEvent] - 'openweathermap:weather-and-forecast:api:local' changed from INITIALIZING to UNKNOWN

2019-02-25 13:29:16.142 [me.event.ThingUpdatedEvent] - Thing 'openweathermap:weather-and-forecast:api:local' has been updated.

2019-02-25 13:29:16.904 [hingStatusInfoChangedEvent] - 'mqtt:topic:a6379cde' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-02-25 13:29:17.027 [hingStatusInfoChangedEvent] - 'mqtt:topic:b27a43be' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-02-25 13:29:17.133 [hingStatusInfoChangedEvent] - 'mqtt:topic:b7afda60' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2019-02-25 13:29:17.236 [hingStatusInfoChangedEvent] - 'mqtt:topic:5117baec' changed from UNINITIALIZED to UNINITIALIZED (BRIDGE_UNINITIALIZED)

==> /var/log/openhab2/openhab.log <==

2019-02-25 13:29:23.715 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.115:8080

2019-02-25 13:29:23.797 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.115:8443

==> /var/log/openhab2/events.log <==

2019-02-25 13:29:28.819 [hingStatusInfoChangedEvent] - 'mqtt:broker:fe9b4b69' changed from UNINITIALIZED to INITIALIZING

2019-02-25 13:29:30.229 [hingStatusInfoChangedEvent] - 'mqtt:broker:fe9b4b69' changed from INITIALIZING to OFFLINE

==> /var/log/openhab2/openhab.log <==

2019-02-25 13:29:31.059 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '192.168.1.115' with clientid paho358691066441 and file store '/var/lib/openhab2/mqtt/192.168.1.115'

==> /var/log/openhab2/events.log <==

2019-02-25 13:29:32.625 [hingStatusInfoChangedEvent] - 'mqtt:topic:a6379cde' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-02-25 13:29:32.788 [hingStatusInfoChangedEvent] - 'mqtt:topic:b27a43be' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-02-25 13:29:32.932 [hingStatusInfoChangedEvent] - 'mqtt:topic:b7afda60' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-02-25 13:29:33.074 [hingStatusInfoChangedEvent] - 'mqtt:broker:fe9b4b69' changed from OFFLINE to ONLINE

2019-02-25 13:29:33.189 [hingStatusInfoChangedEvent] - 'mqtt:topic:5117baec' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2019-02-25 13:29:33.359 [me.event.ThingUpdatedEvent] - Thing 'mqtt:broker:fe9b4b69' has been updated.

2019-02-25 13:29:34.598 [hingStatusInfoChangedEvent] - 'mqtt:topic:a6379cde' changed from INITIALIZING to ONLINE

2019-02-25 13:29:34.731 [hingStatusInfoChangedEvent] - 'mqtt:topic:b27a43be' changed from INITIALIZING to ONLINE

2019-02-25 13:29:34.934 [hingStatusInfoChangedEvent] - 'mqtt:topic:b7afda60' changed from INITIALIZING to ONLINE

2019-02-25 13:29:35.059 [hingStatusInfoChangedEvent] - 'mqtt:topic:5117baec' changed from INITIALIZING to ONLINE

2019-02-25 13:29:36.205 [vent.ItemStateChangedEvent] - MF_Dining_Temperature changed from NULL to UNDEF

2019-02-25 13:29:36.281 [GroupItemStateChangedEvent] - gTemperature changed from NULL to UNDEF through MF_Dining_Temperature

2019-02-25 13:29:36.439 [vent.ItemStateChangedEvent] - MF_Dining_Humidity changed from NULL to UNDEF

2019-02-25 13:29:36.496 [vent.ItemStateChangedEvent] - MF_Office_Temperature changed from NULL to UNDEF

2019-02-25 13:29:36.559 [GroupItemStateChangedEvent] - gHumidity changed from NULL to UNDEF through MF_Dining_Humidity

2019-02-25 13:29:36.621 [vent.ItemStateChangedEvent] - MF_Office_Light changed from NULL to UNDEF

2019-02-25 13:29:36.671 [vent.ItemStateChangedEvent] - MF_Office_Pressure changed from NULL to UNDEF

2019-02-25 13:29:36.710 [vent.ItemStateChangedEvent] - B_Workshop_Temperature changed from NULL to UNDEF

2019-02-25 13:29:36.739 [vent.ItemStateChangedEvent] - MF_Office_Humidity changed from NULL to UNDEF

2019-02-25 13:29:36.767 [vent.ItemStateChangedEvent] - B_Workshop_Pressure changed from NULL to UNDEF

2019-02-25 13:29:36.810 [GroupItemStateChangedEvent] - gLight changed from NULL to OFF through MF_Office_Light

2019-02-25 13:29:36.841 [vent.ItemStateChangedEvent] - B_Workshop_Humidity changed from NULL to UNDEF

2019-02-25 13:29:36.910 [GroupItemStateChangedEvent] - gPressure changed from NULL to UNDEF through MF_Office_Pressure

2019-02-25 13:29:38.523 [hingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from UNINITIALIZED to INITIALIZING

2019-02-25 13:29:38.776 [hingStatusInfoChangedEvent] - 'openweathermap:weather-and-forecast:api:local' changed from UNKNOWN to OFFLINE (COMMUNICATION_ERROR): Total timeout 10000 ms elapsed

2019-02-25 13:29:38.950 [hingStatusInfoChangedEvent] - 'openweathermap:weather-api:api' changed from UNKNOWN to OFFLINE

2019-02-25 13:29:39.476 [hingStatusInfoChangedEvent] - 'ntp:ntp:ourhome' changed from UNINITIALIZED to INITIALIZING

2019-02-25 13:29:40.919 [hingStatusInfoChangedEvent] - 'ntp:ntp:local' changed from INITIALIZING to ONLINE

2019-02-25 13:29:41.720 [vent.ItemStateChangedEvent] - Date changed from NULL to 2019-02-25T13:29:40.715-0500

2019-02-25 13:29:41.842 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:29:40.715-0500 to 2019-02-25T13:29:41.216-0500

2019-02-25 13:29:45.632 [hingStatusInfoChangedEvent] - 'ntp:ntp:ourhome' changed from INITIALIZING to ONLINE

2019-02-25 13:29:45.961 [vent.ItemStateChangedEvent] - Time changed from NULL to 2019-02-25T13:29:45.540-0500

2019-02-25 13:29:46.222 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:29:41.216-0500 to 2019-02-25T13:29:45.540-0500

2019-02-25 13:29:46.329 [vent.ItemStateChangedEvent] - Time changed from 2019-02-25T13:29:45.540-0500 to 2019-02-25T13:29:45.661-0500

2019-02-25 13:29:46.452 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:29:45.540-0500 to 2019-02-25T13:29:45.661-0500

==> /var/log/openhab2/openhab.log <==

2019-02-25 13:29:50.117 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui

2019-02-25 13:29:53.698 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.

2019-02-25 13:29:53.742 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'broker'

2019-02-25 13:29:53.880 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:broker

2019-02-25 13:29:53.929 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:topic

2019-02-25 13:29:53.995 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:message

2019-02-25 13:29:55.322 [ERROR] [penhab.io.transport.mqtt.MqttService] - Error starting broker connection

org.eclipse.paho.client.mqttv3.MqttSecurityException: Not authorized to connect

	at org.eclipse.paho.client.mqttv3.internal.ExceptionHelper.createMqttException(ExceptionHelper.java:28) ~[?:?]

	at org.eclipse.paho.client.mqttv3.internal.ClientState.notifyReceivedAck(ClientState.java:988) ~[?:?]

	at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:145) ~[?:?]

	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?]

	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:?]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:?]

	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:?]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:?]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:?]

	at java.lang.Thread.run(Thread.java:748) [?:?]

==> /var/log/openhab2/events.log <==

2019-02-25 13:29:58.597 [GroupItemStateChangedEvent] - gHumidity changed from UNDEF to 36.0 through MF_Dining_Humidity

2019-02-25 13:29:58.741 [vent.ItemStateChangedEvent] - MF_Dining_Humidity changed from UNDEF to 36.0

2019-02-25 13:29:58.882 [GroupItemStateChangedEvent] - gTemperature changed from UNDEF to 64.4 through MF_Dining_Temperature

2019-02-25 13:29:58.911 [vent.ItemStateChangedEvent] - MF_Dining_Temperature changed from UNDEF to 64.4

2019-02-25 13:30:41.435 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:29:45.661-0500 to 2019-02-25T13:30:41.224-0500

2019-02-25 13:30:45.839 [vent.ItemStateChangedEvent] - Time changed from 2019-02-25T13:29:45.661-0500 to 2019-02-25T13:30:45.667-0500

2019-02-25 13:30:45.882 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:30:41.224-0500 to 2019-02-25T13:30:45.667-0500

2019-02-25 13:31:04.408 [vent.ItemStateChangedEvent] - MF_Office_Humidity changed from UNDEF to 30.6

2019-02-25 13:31:04.432 [GroupItemStateChangedEvent] - gHumidity changed from 36.0 to 33.3 through MF_Office_Humidity

2019-02-25 13:31:04.579 [vent.ItemStateChangedEvent] - MF_Office_Pressure changed from UNDEF to 1004.0

2019-02-25 13:31:04.603 [GroupItemStateChangedEvent] - gPressure changed from UNDEF to 1004.0 through MF_Office_Pressure

2019-02-25 13:31:04.634 [vent.ItemStateChangedEvent] - MF_Office_Temperature changed from UNDEF to 73.1

2019-02-25 13:31:04.660 [GroupItemStateChangedEvent] - gTemperature changed from 64.4 to 68.8 through MF_Office_Temperature

2019-02-25 13:31:41.471 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:30:45.667-0500 to 2019-02-25T13:31:41.248-0500

2019-02-25 13:31:45.882 [vent.ItemStateChangedEvent] - Time changed from 2019-02-25T13:30:45.667-0500 to 2019-02-25T13:31:45.691-0500

2019-02-25 13:31:45.937 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:31:41.248-0500 to 2019-02-25T13:31:45.691-0500

2019-02-25 13:32:11.254 [vent.ItemStateChangedEvent] - B_Workshop_Pressure changed from UNDEF to 1006.0

2019-02-25 13:32:11.285 [GroupItemStateChangedEvent] - gPressure changed from 1004.0 to 1005.0 through B_Workshop_Pressure

2019-02-25 13:32:11.399 [vent.ItemStateChangedEvent] - B_Workshop_Humidity changed from UNDEF to 42.1

2019-02-25 13:32:11.433 [GroupItemStateChangedEvent] - gHumidity changed from 33.3 to 36.2 through B_Workshop_Humidity

2019-02-25 13:32:11.469 [GroupItemStateChangedEvent] - gTemperature changed from 68.8 to 67.8 through B_Workshop_Temperature

2019-02-25 13:32:11.486 [vent.ItemStateChangedEvent] - B_Workshop_Temperature changed from UNDEF to 65.9

2019-02-25 13:32:41.460 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:31:45.691-0500 to 2019-02-25T13:32:41.267-0500

2019-02-25 13:32:45.890 [vent.ItemStateChangedEvent] - Time changed from 2019-02-25T13:31:45.691-0500 to 2019-02-25T13:32:45.717-0500

2019-02-25 13:32:45.926 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:32:41.267-0500 to 2019-02-25T13:32:45.717-0500

2019-02-25 13:33:41.490 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:32:45.717-0500 to 2019-02-25T13:33:41.287-0500

2019-02-25 13:33:45.907 [vent.ItemStateChangedEvent] - Time changed from 2019-02-25T13:32:45.717-0500 to 2019-02-25T13:33:45.742-0500

2019-02-25 13:33:45.957 [vent.ItemStateChangedEvent] - Date changed from 2019-02-25T13:33:41.287-0500 to 2019-02-25T13:33:45.742-0500

Can you post it again without interleaving the two logs? Honestly, I don’t care at all about events.log in this case.

There are lots of problems here.

MqttBroker connection configuration faulty: host : You need to provide a hostname/IP!

Well, this is clearly s configuration problem with the MQTT Broker Thing. You have an MQTT Broker Thing that doesn’t have a host parameter. So it doesn’t know what to connect to. NOTE: You might have more than one MQTT Broker Thing, you probably have another one that is properly configured.

Cannot add “ItemChannelLink” with key “MF_Office_Light -> mqtt:topic:b27a43be:OL01”. It exists already from provider “GenericItemChannelLinkProvider”! Failed to add a second with the same UID from provider “ManagedItemChannelLinkProvider”!

Did you by chance start with configuring Items and Things in PaperUI and then move to configuration in text files? This warning indicates that you are trying to define the link between a Channel and an Item twice. This usually happens when one deletes an Item from PaperUI without first deleting the Link to the Channel. Then when you recreate the Item in a .items file and supply the channel there it generates a warning because the Link still exists in JSONDB. The only way I know to fix this is to remove the Links from the JSONDB file manually, while OH is not running.

Error starting broker connection

This error indicates that your MQTT Broker Thing as configured is probably configured with an incorrect username or password. Again, since it seems to work after everything starts up you probably have two MQTT Broker Things configured, one of which is miss configured.

Your problems all appear to be miss configured Things, not something structural or a bug in the core or the bindings.

1 Like

Thanks Rick! That was only from the openhab.log file.
I will start to track down the things you indicated and see if I can find what is causing the errors.

You’ve interleaved sections of openhab.log and events.log above.

I commented everything out in the mqtt.cfg file as that is what I had set up originally and cleared the log files and the first line in the event log file is still

2019-02-25 15:16:22.933 [WARN ] [.MqttBrokerConnectionServiceInstance] - MqttBroker connection configuration faulty: host : You need to provide a hostname/IP!

I set the connection to the IP that my Pi is set at for the MQTT connection and 1883 for the port. I’m not sure where else I need to change it.

Close OH.

Open /var/lib/openhab2/jsondb/<some long name>Things.json and search through it to see if there is more than one MQTT Broker Thing defined. Do you have Things defined in .things files?

Do you have both the MQTT 1 and MQTT 2 binding installed?

The only entries in my Thing file are for time and weather. I do not have any MQTT 1 bindings loaded.

I have a relay I’m working with, run by a ESP8266 with Tasmota, that “works”. If I switch it ON/OFF in the Control tab in Paper UI it works like it suppose to. If I do the same on the Basic UI, the graphics for the switch tends to bounce on and off, not always following the actual ON/OFF motion like in the Control tab. That probably has something to do with the MQTT I’m guessing.

Something else I noticed when I commented out all the entries in the mqtt.cfg file and rebooted, the MQTT entry under Configuration > Services is gone in the Paper UI.

Here is what is in the Thing.json file.

{
  "mqtt:topic:b7afda60": {
    "class": "org.eclipse.smarthome.core.thing.internal.ThingImpl",
    "value": {
      "label": "Dining Room",
      "bridgeUID": {
        "segments": [
          "mqtt",
          "broker",
          "fe9b4b69"
        ]
      },
      "channels": [
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "b7afda60",
              "DHT11"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/DHT11/POWER",
              "stateTopic": "tele/DHT11/SENSOR",
              "transformationPattern": "JSONPATH:$.DHT11.Temperature"
            }
          },
          "properties": {},
          "defaultTags": []
        },
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "b7afda60",
              "DHT11H"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/DHT11/POWER",
              "stateTopic": "tele/DHT11/SENSOR",
              "transformationPattern": "JSONPATH:$.DHT11.Humidity"
            }
          },
          "properties": {},
          "defaultTags": []
        }
      ],
      "configuration": {
        "properties": {}
      },
      "properties": {},
      "uid": {
        "segments": [
          "mqtt",
          "topic",
          "b7afda60"
        ]
      },
      "thingTypeUID": {
        "segments": [
          "mqtt",
          "topic"
        ]
      }
    }
  },
  "mqtt:topic:a6379cde": {
    "class": "org.eclipse.smarthome.core.thing.internal.ThingImpl",
    "value": {
      "label": "Office Comfort",
      "bridgeUID": {
        "segments": [
          "mqtt",
          "broker",
          "fe9b4b69"
        ]
      },
      "channels": [
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "a6379cde",
              "BME280T"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/BME280-1/POWER",
              "stateTopic": "tele/BME280-1/SENSOR",
              "transformationPattern": "JSONPATH:$.BME280.Temperature"
            }
          },
          "properties": {},
          "defaultTags": []
        },
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "a6379cde",
              "BME280-1H"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/BME-1/POWER",
              "stateTopic": "tele/BME280-1/SENSOR",
              "transformationPattern": "JSONPATH:$.BME280.Humidity"
            }
          },
          "properties": {},
          "defaultTags": []
        },
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "a6379cde",
              "BME280-1P"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/BME280-1/POWER",
              "stateTopic": "tele/BME280-1/SENSOR",
              "transformationPattern": "JSONPATH:$.BME280.Pressure"
            }
          },
          "properties": {},
          "defaultTags": []
        }
      ],
      "configuration": {
        "properties": {}
      },
      "properties": {},
      "uid": {
        "segments": [
          "mqtt",
          "topic",
          "a6379cde"
        ]
      },
      "thingTypeUID": {
        "segments": [
          "mqtt",
          "topic"
        ]
      }
    }
  },
  "mqtt:broker:fe9b4b69": {
    "class": "org.eclipse.smarthome.core.thing.internal.BridgeImpl",
    "value": {
      "label": "MQTT Broker",
      "channels": [],
      "configuration": {
        "properties": {
          "publickeypin": true,
          "password": "################",
          "clientid": "################",
          "lastwill_qos": 0,
          "qos": 0,
          "retain": true,
          "host": "192.168.###.###",
          "secure": false,
          "certificatepin": true,
          "keep_alive_time": 60000,
          "reconnect_time": 60000,
          "username": "openhabian"
        }
      },
      "properties": {},
      "uid": {
        "segments": [
          "mqtt",
          "broker",
          "fe9b4b69"
        ]
      },
      "thingTypeUID": {
        "segments": [
          "mqtt",
          "broker"
        ]
      }
    }
  },
  "ntp:ntp:local": {
    "class": "org.eclipse.smarthome.core.thing.internal.ThingImpl",
    "value": {
      "label": "Local Time",
      "channels": [
        {
          "acceptedItemType": "DateTime",
          "kind": "STATE",
          "uid": {
            "segments": [
              "ntp",
              "ntp",
              "local",
              "dateTime"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "ntp",
              "dateTime-channel"
            ]
          },
          "label": "Date",
          "description": "NTP refreshed date \u0026 time",
          "configuration": {
            "properties": {}
          },
          "properties": {},
          "defaultTags": []
        },
        {
          "acceptedItemType": "String",
          "kind": "STATE",
          "uid": {
            "segments": [
              "ntp",
              "ntp",
              "local",
              "string"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "ntp",
              "string-channel"
            ]
          },
          "label": "Date",
          "description": "NTP refreshed date \u0026 time",
          "configuration": {
            "properties": {
              "DateTimeFormat": "MM-dd-yyyy HH:mm:ss z"
            }
          },
          "properties": {},
          "defaultTags": []
        }
      ],
      "configuration": {
        "properties": {
          "timeZone": "America/New_York",
          "hostname": "0.pool.ntp.org",
          "serverPort": 123,
          "refreshInterval": 60,
          "refreshNtp": 30
        }
      },
      "properties": {},
      "uid": {
        "segments": [
          "ntp",
          "ntp",
          "local"
        ]
      },
      "thingTypeUID": {
        "segments": [
          "ntp",
          "ntp"
        ]
      }
    }
  },
  "mqtt:topic:b27a43be": {
    "class": "org.eclipse.smarthome.core.thing.internal.ThingImpl",
    "value": {
      "label": "Generic MQTT Thing",
      "bridgeUID": {
        "segments": [
          "mqtt",
          "broker",
          "fe9b4b69"
        ]
      },
      "channels": [
        {
          "acceptedItemType": "Switch",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "b27a43be",
              "OL01"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "switch"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/Office_Light/POWER",
              "stateTopic": "stat/Office_Light/POWER"
            }
          },
          "properties": {},
          "defaultTags": []
        }
      ],
      "configuration": {
        "properties": {}
      },
      "properties": {},
      "uid": {
        "segments": [
          "mqtt",
          "topic",
          "b27a43be"
        ]
      },
      "thingTypeUID": {
        "segments": [
          "mqtt",
          "topic"
        ]
      }
    }
  },
  "mqtt:topic:5117baec": {
    "class": "org.eclipse.smarthome.core.thing.internal.ThingImpl",
    "value": {
      "label": "Basement",
      "bridgeUID": {
        "segments": [
          "mqtt",
          "broker",
          "fe9b4b69"
        ]
      },
      "channels": [
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "5117baec",
              "BME280-2T"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/BME280-2/POWER",
              "stateTopic": "tele/BME280-2/SENSOR",
              "transformationPattern": "JSONPATH:$.BME280.Temperature"
            }
          },
          "properties": {},
          "defaultTags": []
        },
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "5117baec",
              "BME280-2H"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/BME280-2/POWER",
              "stateTopic": "tele/BME280-2/SENSOR",
              "transformationPattern": "JSONPATH:$.BME280.Humidity"
            }
          },
          "properties": {},
          "defaultTags": []
        },
        {
          "acceptedItemType": "Number",
          "kind": "STATE",
          "uid": {
            "segments": [
              "mqtt",
              "topic",
              "5117baec",
              "BME280-2P"
            ]
          },
          "channelTypeUID": {
            "segments": [
              "mqtt",
              "number"
            ]
          },
          "configuration": {
            "properties": {
              "commandTopic": "cmnd/BME280-2/POWER",
              "stateTopic": "tele/BME280-2/SENSOR",
              "transformationPattern": "JSONPATH:$.BME280.Pressure"
            }
          },
          "properties": {},
          "defaultTags": []
        }
      ],
      "configuration": {
        "properties": {}
      },
      "properties": {},
      "uid": {
        "segments": [
          "mqtt",
          "topic",
          "5117baec"
        ]
      },
      "thingTypeUID": {
        "segments": [
          "mqtt",
          "topic"
        ]
      }
    }
  }
}

The cfg file is for mqtt1. MQTT2 puts all of that config info into the Broker Thing.
If you can control the Channel through PaperUI then the binding and Things and Channels are all configured correctly, or at least well enough to send the messages.

What do you see in events.log? Show your Item configs.

I have the share and config folders mapped so I can get to them through the Windows Explorer. I see in the openHAB-share/openhab2-userdata/mqtt/ folder another folder labeled
192.168.1.115 which is the location of my RPi on my network. Inside that is another folder labeled
pahoxxxxxxxxxxxxxxxx-tcpxxxxxxxxxxxxxxxxxx. Inside that folder is a .lck file 0 bytes.

Ok I’m looking through more files and in

 **openHAB-share/openhab2-userdata/config/org_apache_felix_cm_impl_DynamicBindings.config** 

file I see these lines in that file

SymmetricKeyCipher="mvn:org.eclipse.smarthome.auth/org.eclipse.smarthome.auth.oauth2client/0.10.0.oh240"
org.openhab.addons="mvn:org.openhab.core/org.openhab.core.karaf/2.4.0"
org.openhab.dashboard="mvn:org.openhab.core/org.openhab.ui.dashboard/2.4.0"
org.openhab.mqtt="mvn:org.openhab.io/org.openhab.io.transport.mqtt/1.13.0"

So it looks like there is the reference to mqtt/1.13.0 in that file. I removed that reference and the MQTT error is still showing in the log file.
Looking farther into the openhab2-userdata/config folder in the profile.config file and I see 2 references to MQTT.

feature.esh-io-transport-mqtt/0.10.0.oh240="esh-io-transport-mqtt/0.10.0.oh240"

and 

feature.openhab-transport-mqtt/2.4.0="openhab-transport-mqtt/2.4.0"

I am removing the first reference, clearing the log files and rebooting.
Well Damn!! After removing all that stuff I still get

2019-02-26 00:06:38.020 [WARN ] [.MqttBrokerConnectionServiceInstance] - MqttBroker connection configuration faulty: host : You need to provide a hostname/IP!

And everything still works in the Basic UI. Anything else I should look at?

John

It looks to me you somehow mixed up old mqtt1 tutorials with the newer mqtt2 tutorials in the process of configuring your mqtt.

Two more things to check:
-Log into karaf and execute bundle:list | grep -i mqtt. It should look similar to:

223 x Active x  80 x 1.2.0                 x Paho MQTT Client
237 x Active x  80 x 2.5.0.201902161217    x MQTT Binding
238 x Active x  80 x 2.5.0.201902161217    x MQTT Thing Binding
247 x Active x  80 x 2.5.0.201902160309    x openHAB Core :: Bundles :: MQTT Transport

Next thing to check is if you have some old config stored:
Stop openHAB, delete /userdata/config/org/openhab/mqtt.config
Start openHAB.
This file will be recreated during openHAB start, but always make a backup of files before you are deleting them.

Sorry sihui, you’re talking about things that are way over my head here. I can ssh and do some stuff but I don’t know anything about logging into karaf. But I’m willing to learn.

That is the reason why I linked the word karaf with the docs. Just klick on it and follow them.

Ok I figured it out. This is what it shows

212 x Active   x  80 x 1.13.0                 x openHAB MQTT Transport Bundle
213 x Active   x  80 x 1.13.0                 x openHAB MQTT Persistence Bundle

I just deleted that file and rebooting