OpenHab not connecting to MQTT

RPI 3. Download and install openHABian v1.4.1.
Type openhabian-config and install mosquitto.
Type mosquitto_sub -t "#" -v
Type mosquitto_pub -t "testsw" -m "test"
And mosquitto_sub show testsw test. It is OK.

In PapperUI I install “MQTT Actions”, “MQTT Binding”.

In test.items:

Switch mqttsw1 "Switch 1" {mqtt=">[localmqtt:testsw/1:command:on:default],>[localmqtt:testsw/1:command:off:default]"}
Switch mqttsw2 "Switch 2" {mqtt="<[localmqtt:testsw/1:state:ON:ON],<[localmqtt:testsw/1:state:OFF:OFF]"}

That mean that if I toggle mqttsw1 - then mqttsw2 must be toggled too.

In test.sitemap:

sitemap test label="Мой оч умный дом" {
	Frame label="Тестируем mqtt" {
		Switch item=mqttsw1
		Switch item=mqttsw2
	}
}

In mqtt.cfg:

localmqtt.url=tcp://localhost:1883
localmqtt.clientId=RPI3OH22

In karaf console:

log:set DEBUG org.openhab.binding.mqtt

In Log View on page openhabianpi:9001:

2018-05-18 19:33:14.960 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-18 19:33:16.335 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.1.52
2018-05-18 19:33:16.461 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.67:8080
2018-05-18 19:33:16.465 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.67:8443
2018-05-18 19:33:51.399 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items'
2018-05-18 19:33:55.575 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-18 19:33:56.279 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap'
2018-05-18 19:33:59.134 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-18 19:33:59.262 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-18 19:33:59.404 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-18 19:34:00.330 [DEBUG] [org.openhab.binding.mqtt            ] - BundleEvent STARTING - org.openhab.binding.mqtt
2018-05-18 19:34:00.338 [DEBUG] [.binding.mqtt.internal.MqttActivator] - MQTT binding has been started.
2018-05-18 19:34:00.342 [DEBUG] [org.openhab.binding.mqtt            ] - BundleEvent STARTED - org.openhab.binding.mqtt
2018-05-18 19:34:00.407 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'mqttsw1' : 0 subscribers, 2 publishers
2018-05-18 19:34:00.427 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'mqttsw2' : 2 subscribers, 0 publishers
2018-05-18 19:34:00.439 [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=188, service.id=310, service.bundleid=209, service.scope=bundle} - org.openhab.binding.mqtt
2018-05-18 19:34:00.447 [DEBUG] [org.openhab.binding.mqtt            ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler}={event.topics=openhab/*, component.name=org.openhab.binding.mqtt.MqttItemBinding, component.id=187, service.id=312, service.bundleid=209, service.scope=bundle} - org.openhab.binding.mqtt
2018-05-18 19:34:00.471 [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=189, service.id=313, service.bundleid=209, service.scope=bundle} - org.openhab.binding.mqtt
2018-05-18 19:34:00.486 [DEBUG] [ng.mqtt.internal.MqttEventBusBinding] - MQTT: Activating event bus binding.
2018-05-18 19:34:00.511 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:broker
2018-05-18 19:34:00.515 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:topic
2018-05-18 19:34:00.519 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:message
2018-05-18 19:35:00.053 [DEBUG] [inding.mqtt.internal.MqttItemBinding] - Publishing command ON to testsw/1
==> /var/log/openhab2/events.log <==
2018-05-18 19:35:00.062 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
2018-05-18 19:35:00.126 [vent.ItemStateChangedEvent] - mqttsw1 changed from NULL to ON
2018-05-18 19:35:22.673 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
==> /var/log/openhab2/openhab.log <==
2018-05-18 19:35:22.673 [DEBUG] [inding.mqtt.internal.MqttItemBinding] - Publishing command OFF to testsw/1
==> /var/log/openhab2/events.log <==
2018-05-18 19:35:22.694 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF
==> /var/log/openhab2/openhab.log <==
2018-05-18 19:48:21.127 [DEBUG] [inding.mqtt.internal.MqttItemBinding] - Publishing command ON to testsw/1
==> /var/log/openhab2/events.log <==
2018-05-18 19:48:21.139 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
2018-05-18 19:48:21.159 [vent.ItemStateChangedEvent] - mqttsw1 changed from OFF to ON
==> /var/log/openhab2/openhab.log <==
2018-05-18 19:48:22.248 [DEBUG] [inding.mqtt.internal.MqttItemBinding] - Publishing command OFF to testsw/1
==> /var/log/openhab2/events.log <==
2018-05-18 19:48:22.252 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
2018-05-18 19:48:22.278 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF

And Swithes not toggled!!!
And mosquitto_sub -t "#" -v** says none/quiet!!!
What is this???

Please tryout this for items:

Switch mqttsw1 "Switch 1" {mqtt=">[localmqtt:testsw/1:command:*:${command}]"}
Switch mqttsw2 "Switch 2" {mqtt="<[localmqtt:testsw/1:state:REGEX((.*))]"}

That’s because your binding definitions are wrong

No need to shout we can see what you did. Shout at your computer, hardware, whatever, but not on the forum, please

Switch mqttsw1 "Switch 1" { mqtt=">[localmqtt:testsw/1:command:*:default]" }
Switch mqttsw2 "Switch 2" { mqtt="<[localmqtt:testsw/1:state:default]" }

The first switch, There are no command on or off they are ON of OFF. We can do command:*:default to do both.
The second switch (In bound) the inbound binding definition only take 4 parameters not 5.

Read the docs next time before shouting on the forum
You’re welcome

2 Likes

Thanx for answer.
Yours solution not working too. https://www.youtube.com/watch?v=0pSnYrIDbng

Mr @vzorglub! You are wrong! This my procedure work in openHABian v1.3 release (OH2.2). Here is proof https://www.youtube.com/watch?v=XPWyyqmdrVI

Mr @Udo_Hartmann. Thanx for answer. Tryout not work

I am not!
I have been running OH with mqtt in plenty of configurations for for than 3 years and helped countless users with it already.

I have had a look at your video and everything seems right but mqttsw2 doesn’t get the inbound message. And mqqtsw1 doesn’t send the message out even thoough the says it does. It should. So now let’s calm down and figure it out.

Your mqtt.cfg file:

change:
localmqtt.url=tcp://localhost:1883
to:
localmqtt.url=tcp://127.0.0.1:1883

Then delete the items file and create a new one an TYPE IN the defintions:

Switch mqttsw1 "Switch 1" { mqtt=">[localmqtt:testsw/1:command:*:default]" }
Switch mqttsw2 "Switch 2" { mqtt="<[localmqtt:testsw/1:state:default]" }

Do NOT copy and paste from the forum if you can avoid it. Sometimes hidden characters get into there and others get changes because of the browser.

Once done, Action your switch and monitor the logs

First, there is a difference between testsw/1 and testsw1 (you did a publish to the latter and got no answer on the former, which is correct).

Second, I recommend not to install all three addons action, persistence and binding at once. Please try first if mqtt works as expected if only the binding is installed. When the binding is working as expected, install the action in addition, test it and then install persistence. By the way: do you really need all three of them?

Third, please start mosquitto in verbosity mode:

sudo systemctl stop mosquitto.service
mosquitto -v

You then will get information about connected clients through the console.

I had also issues when first time starting mqtt, turned out it was all typos… :slight_smile: Sometimes I’m so exited… :wink:

1 Like

I try this. Nothing changes.
Also I try change to localmqtt.url=tcp://192.168.1.67:1883
Also I try change to this: localmqtt2.url=tcp://127.0.0.1:1883, localmqtt2.clientId=RPI3OH22_3. Becouse OH have problem if change something one.
Aaaannnddd - nothing!

If you see video - there is writing Publishing command ON to testsw/1.
OH thing that send mqtt packets success.
But mosquitto does not know anything : )

When I change .url LogViewer spit out:

[ERROR] [org.apache.felix.configadmin        ] - Cannot use configuration org.openhab.mqtt for [org.openhab.io.transport.mqtt.MqttService, org.osgi.service.cm.ManagedService, id=307, bundle=208/mvn:org.openhab.io/org.openhab.io.transport.mqtt/1.11.0]: No visibility to configuration bound to mvn:org.openhab.action/org.openhab.action.mqtt/1.11.0

I rebooting RPI. Error not appeared.

2018-05-19 00:22:20.957 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-19 00:22:22.714 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.67:8080
2018-05-19 00:22:22.722 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.67:8443
2018-05-19 00:22:57.451 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test2.items'
2018-05-19 00:23:01.041 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-19 00:23:02.151 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap'
2018-05-19 00:23:04.548 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-19 00:23:04.660 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-19 00:23:04.776 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-19 00:23:05.071 [DEBUG] [org.openhab.binding.mqtt            ] - BundleEvent STARTING - org.openhab.binding.mqtt
2018-05-19 00:23:05.077 [DEBUG] [.binding.mqtt.internal.MqttActivator] - MQTT binding has been started.
2018-05-19 00:23:05.080 [DEBUG] [org.openhab.binding.mqtt            ] - BundleEvent STARTED - org.openhab.binding.mqtt
2018-05-19 00:23:05.129 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'mqttsw1' : 0 subscribers, 1 publishers
2018-05-19 00:23:05.147 [DEBUG] [binding.mqtt.internal.MqttItemConfig] - Loaded MQTT config for item 'mqttsw2' : 1 subscribers, 0 publishers
2018-05-19 00:23:05.153 [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=189, service.id=311, service.bundleid=209, service.scope=bundle} - org.openhab.binding.mqtt
2018-05-19 00:23:05.160 [DEBUG] [org.openhab.binding.mqtt            ] - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler}={event.topics=openhab/, component.name=org.openhab.binding.mqtt.MqttItemBinding, component.id=188, service.id=313, service.bundleid=209, service.scope=bundle} - org.openhab.binding.mqtt
2018-05-19 00:23:05.187 [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=190, service.id=314, service.bundleid=209, service.scope=bundle} - org.openhab.binding.mqtt
2018-05-19 00:23:05.210 [DEBUG] [ng.mqtt.internal.MqttEventBusBinding] - MQTT: Activating event bus binding.
2018-05-19 00:23:05.235 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:broker
2018-05-19 00:23:05.239 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:topic
2018-05-19 00:23:05.242 [WARN ] [mqtt.internal.MqttPersistenceService] - mqtt-persistence:message
==> /var/log/openhab2/events.log <==
2018-05-19 00:23:25.002 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
==> /var/log/openhab2/openhab.log <==
2018-05-19 00:23:25.026 [DEBUG] [inding.mqtt.internal.MqttItemBinding] - Publishing command ON to testsw/1
==> /var/log/openhab2/events.log <==
2018-05-19 00:23:25.044 [vent.ItemStateChangedEvent] - mqttsw1 changed from NULL to ON
2018-05-19 00:23:25.870 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
==> /var/log/openhab2/openhab.log <==
2018-05-19 00:23:25.876 [DEBUG] [inding.mqtt.internal.MqttItemBinding] - Publishing command OFF to testsw/1
==> /var/log/openhab2/events.log <==
2018-05-19 00:23:25.881 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF

Ok.
Start from scratch
We wil do a minimal mqtt binding config:

    • Uninstall the mqtt persistence first
    • Then uninstall the mqtt action
    • Then uninstall the mqtt binding
    • Stop openhab
    • delete the mqtt.cfg
    • Start openHAB
    • Install the mqtt binding ONLY
    • Put in the info in the new mqtt.cfg:
    • Change this line ONLY
    • localmqtt.url=tcp://127.0.0.1:1883
    • Edit the items file
    • Test your switch

says:

[00:30:35] root@openHABianPi:~# systemctl stop mosquitto.service
[00:30:42] root@openHABianPi:~# mosquitto -v
1526679047: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526679047: Using default config.
1526679047: Opening ipv4 listen socket on port 1883.
1526679047: Opening ipv6 listen socket on port 1883.

All mosquitto.log from install openhabian to now:

1526656733: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526656733: Config loaded from /etc/mosquitto/mosquitto.conf.
1526656733: Opening ipv4 listen socket on port 1883.
1526656733: Opening ipv6 listen socket on port 1883.
1526656737: Error in poll: Interrupted system call.
1526656737: mosquitto version 1.4.10 terminating
1526656738: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526656738: Config loaded from /etc/mosquitto/mosquitto.conf.
1526656738: Opening ipv4 listen socket on port 1883.
1526656738: Opening ipv6 listen socket on port 1883.
1526656939: Error in poll: Interrupted system call.
1526656939: mosquitto version 1.4.10 terminating
1526656956: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526656956: Config loaded from /etc/mosquitto/mosquitto.conf.
1526656956: Opening ipv4 listen socket on port 1883.
1526656956: Opening ipv6 listen socket on port 1883.
1526657220: Error in poll: Interrupted system call.
1526657220: mosquitto version 1.4.10 terminating
1526657246: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526657246: Config loaded from /etc/mosquitto/mosquitto.conf.
1526657246: Opening ipv4 listen socket on port 1883.
1526657246: Opening ipv6 listen socket on port 1883.
1526657520: New connection from ::1 on port 1883.
1526657520: New client connected from ::1 as mosqsub/1010-openHABian (c1, k60).
1526657553: Socket error on client mosqsub/1010-openHABian, disconnecting.
1526658304: New connection from ::1 on port 1883.
1526658304: New client connected from ::1 as mosqpub/1236-openHABian (c1, k60).
1526658304: Client mosqpub/1236-openHABian disconnected.
1526658311: New connection from ::1 on port 1883.
1526658311: New client connected from ::1 as mosqsub/1237-openHABian (c1, k60).
1526658314: New connection from ::1 on port 1883.
1526658314: New client connected from ::1 as mosqpub/1239-openHABian (c1, k60).
1526658314: Client mosqpub/1239-openHABian disconnected.
1526658317: Socket error on client mosqsub/1237-openHABian, disconnecting.
1526658330: New connection from ::1 on port 1883.
1526658330: New client connected from ::1 as mosqsub/1245-openHABian (c1, k60).
1526659074: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526659669: Socket error on client mosqsub/1245-openHABian, disconnecting.
1526659674: Error in poll: Interrupted system call.
1526659674: mosquitto version 1.4.10 terminating
1526659701: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526659701: Config loaded from /etc/mosquitto/mosquitto.conf.
1526659701: Opening ipv4 listen socket on port 1883.
1526659701: Opening ipv6 listen socket on port 1883.
1526660070: New connection from ::1 on port 1883.
1526660070: New client connected from ::1 as mosqsub/1010-openHABian (c1, k60).
1526660104: Socket error on client mosqsub/1010-openHABian, disconnecting.
1526660112: Error in poll: Interrupted system call.
1526660112: mosquitto version 1.4.10 terminating
1526660139: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526660139: Config loaded from /etc/mosquitto/mosquitto.conf.
1526660139: Opening ipv4 listen socket on port 1883.
1526660139: Opening ipv6 listen socket on port 1883.
1526660252: New connection from ::1 on port 1883.
1526660252: New client connected from ::1 as mosqsub/966-openHABianP (c1, k60).
1526660383: Socket error on client mosqsub/966-openHABianP, disconnecting.
1526660771: New connection from ::1 on port 1883.
1526660771: New client connected from ::1 as mosqsub/1257-openHABian (c1, k60).
1526661074: Socket error on client mosqsub/1257-openHABian, disconnecting.
1526661144: Error in poll: Interrupted system call.
1526661144: mosquitto version 1.4.10 terminating
1526661171: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526661171: Config loaded from /etc/mosquitto/mosquitto.conf.
1526661171: Opening ipv4 listen socket on port 1883.
1526661171: Opening ipv6 listen socket on port 1883.
1526661318: New connection from ::1 on port 1883.
1526661318: New client connected from ::1 as mosqsub/968-openHABianP (c1, k60).
1526661928: New connection from ::1 on port 1883.
1526661928: New client connected from ::1 as mosqsub/1187-openHABian (c1, k60).
1526661961: New connection from 192.168.1.175 on port 1883.
1526661961: New client connected from 192.168.1.175 as lens_A1kTbUeBsUadtEw4IfMi6xOh6bE (c1, k120).
1526662122: New connection from ::1 on port 1883.
1526662122: New client connected from ::1 as mosqpub/1248-openHABian (c1, k60).
1526662122: Client mosqpub/1248-openHABian disconnected.
1526662140: Socket error on client lens_A1kTbUeBsUadtEw4IfMi6xOh6bE, disconnecting.
1526662999: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526663109: Socket error on client mosqsub/968-openHABianP, disconnecting.
1526664800: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526665118: Socket error on client mosqsub/1187-openHABian, disconnecting.
1526666601: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526666677: New connection from 192.168.1.36 on port 1883.
1526666677: New client connected from 192.168.1.36 as SuperIOT (c1, k60).
1526666677: Client SuperIOT disconnected.
1526666695: New connection from ::1 on port 1883.
1526666695: New client connected from ::1 as mosqsub/2210-openHABian (c1, k60).
1526666704: New connection from 192.168.1.36 on port 1883.
1526666704: New client connected from 192.168.1.36 as SuperIOT (c1, k60).
1526666704: Client SuperIOT disconnected.
1526666789: New connection from 192.168.1.36 on port 1883.
1526666789: New client connected from 192.168.1.36 as SuperIOT (c1, k60).
1526666789: Client SuperIOT disconnected.
1526666811: New connection from 192.168.1.36 on port 1883.
1526666811: New client connected from 192.168.1.36 as SuperIOT (c1, k60).
1526666811: Client SuperIOT disconnected.
1526668359: Socket error on client mosqsub/2210-openHABian, disconnecting.
1526668402: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526670203: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526670492: New connection from ::1 on port 1883.
1526670492: New client connected from ::1 as mosqsub/2887-openHABian (c1, k60).
1526670974: New connection from ::1 on port 1883.
1526670974: New client connected from ::1 as mosqpub/3033-openHABian (c1, k60).
1526670974: Client mosqpub/3033-openHABian disconnected.
1526672004: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526672191: New connection from ::1 on port 1883.
1526672191: New client connected from ::1 as mosqpub/3270-openHABian (c1, k60).
1526672191: Client mosqpub/3270-openHABian disconnected.
1526672222: New connection from ::1 on port 1883.
1526672222: New client connected from ::1 as mosqpub/3277-openHABian (c1, k60).
1526672222: Client mosqpub/3277-openHABian disconnected.
1526672226: New connection from ::1 on port 1883.
1526672226: New client connected from ::1 as mosqpub/3278-openHABian (c1, k60).
1526672226: Client mosqpub/3278-openHABian disconnected.
1526673805: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526674308: Socket error on client mosqsub/2887-openHABian, disconnecting.
1526675606: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526677407: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1526677495: New connection from ::1 on port 1883.
1526677495: New client connected from ::1 as mosqsub/4290-openHABian (c1, k60).
1526678489: Socket error on client mosqsub/4290-openHABian, disconnecting.
1526678492: Error in poll: Interrupted system call.
1526678492: mosquitto version 1.4.10 terminating
1526678515: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526678515: Config loaded from /etc/mosquitto/mosquitto.conf.
1526678515: Opening ipv4 listen socket on port 1883.
1526678515: Opening ipv6 listen socket on port 1883.
1526679042: Error in poll: Interrupted system call.
1526679042: mosquitto version 1.4.10 terminating

So openHAB does not connect at all (should be RPI3OH22

1526662122: New client connected from ::1 as RPI3OH22

or something similar.

@Udo_Hartmann
Yes, but in the OH log it says connected.
So the question is: what is OH connected to??
Unless he has somehow managed to get two instances of mosquitto running and OH connects to one whilst he monitor the other?

  1. I reinstall OH.
  2. Install mosqitto from openhabian-config.
  3. Install the mqtt binding ONLY
  4. in mqtt.cfg put: localmqtt.url=tcp://127.0.0.1:1883 and localmqtt.clientId=RPI3OH22
  5. create items and sitemap
  6. testing switch
  7. Also - it does not work

mosquitto.log:

1526721255: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526721255: Config loaded from /etc/mosquitto/mosquitto.conf.
1526721255: Opening ipv4 listen socket on port 1883.
1526721255: Opening ipv6 listen socket on port 1883.
1526721260: Error in poll: Interrupted system call.
1526721260: mosquitto version 1.4.10 terminating
1526721260: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526721260: Config loaded from /etc/mosquitto/mosquitto.conf.
1526721260: Opening ipv4 listen socket on port 1883.
1526721260: Opening ipv6 listen socket on port 1883.
1526721349: New connection from ::1 on port 1883.
1526721349: New client connected from ::1 as mosqsub/4007-openHABian (c1, k60).
1526721393: New connection from ::1 on port 1883.
1526721393: New client connected from ::1 as mosqpub/4014-openHABian (c1, k60).
1526721393: Client mosqpub/4014-openHABian disconnected.
1526721617: Socket error on client mosqsub/4007-openHABian, disconnecting.
1526721723: New connection from 127.0.0.1 on port 1883.
1526721723: New client connected from 127.0.0.1 as RPI3OH22 (c1, k60).
1526721969: New connection from ::1 on port 1883.

Command mosquitto_sub -t “#”: empty

LogViewer:

2018-05-19 11:33:08.305 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.179:8080
2018-05-19 11:33:08.349 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.179:8443
2018-05-19 11:33:19.006 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-19 11:33:19.476 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
2018-05-19 11:33:19.570 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.179:8080
2018-05-19 11:33:19.573 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.179:8443
2018-05-19 12:02:19.966 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-19 12:02:20.510 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-19 12:02:20.851 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-19 12:02:20.950 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-19 12:04:45.288 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2018-05-19 12:04:55.116 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2018-05-19 12:04:55.142 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2018-05-19 12:04:55.159 [INFO ] [er.internal.HomeBuilderDashboardTile] - Stopped Home Builder
2018-05-19 12:04:55.184 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
==> /var/log/openhab2/events.log <==
2018-05-19 12:02:07.876 [thome.event.ExtensionEvent] - Extension 'package-standard' has been installed.
2018-05-19 12:02:20.987 [thome.event.ExtensionEvent] - Extension 'ui-homebuilder' has been installed.
2018-05-19 12:02:21.005 [thome.event.ExtensionEvent] - Extension 'ui-basic' has been installed.
2018-05-19 12:02:21.007 [thome.event.ExtensionEvent] - Extension 'ui-habpanel' has been installed.
2018-05-19 12:02:21.009 [thome.event.ExtensionEvent] - Extension 'ui-paper' has been installed.
==> /var/log/openhab2/openhab.log <==
2018-05-19 12:05:26.442 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-19 12:05:27.653 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.1.179
2018-05-19 12:05:27.938 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.147:8080
2018-05-19 12:05:27.944 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.147:8443
2018-05-19 12:06:05.752 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-19 12:06:09.274 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-19 12:06:09.413 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-19 12:06:09.577 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
==> /var/log/openhab2/events.log <==
2018-05-19 12:19:12.323 [thome.event.ExtensionEvent] - Extension 'binding-mqtt1' has been installed.
==> /var/log/openhab2/openhab.log <==
2018-05-19 12:22:03.403 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2018-05-19 12:22:03.410 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'localmqtt'
2018-05-19 12:23:28.132 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items'
2018-05-19 12:23:51.134 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.items'
2018-05-19 12:23:51.361 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.items'
2018-05-19 12:24:13.891 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap'
2018-05-19 12:24:52.145 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.sitemap'
2018-05-19 12:24:52.235 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.sitemap'
==> /var/log/openhab2/events.log <==
2018-05-19 12:25:52.669 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
2018-05-19 12:25:52.724 [vent.ItemStateChangedEvent] - mqttsw1 changed from NULL to ON
2018-05-19 12:26:12.813 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
2018-05-19 12:26:12.854 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF

Reboot RPI.
Logviewer:

2018-05-19 11:33:08.305 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.179:8080
2018-05-19 11:33:08.349 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.179:8443
2018-05-19 11:33:19.006 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-19 11:33:19.476 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
2018-05-19 11:33:19.570 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.179:8080
2018-05-19 11:33:19.573 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.179:8443
2018-05-19 12:02:19.966 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-19 12:02:20.510 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-19 12:02:20.851 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-19 12:02:20.950 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-19 12:04:45.288 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2018-05-19 12:04:55.116 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2018-05-19 12:04:55.142 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2018-05-19 12:04:55.159 [INFO ] [er.internal.HomeBuilderDashboardTile] - Stopped Home Builder
2018-05-19 12:04:55.184 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
2018-05-19 12:05:26.442 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-19 12:05:27.653 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.1.179
2018-05-19 12:05:27.938 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.147:8080
2018-05-19 12:05:27.944 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.147:8443
2018-05-19 12:06:05.752 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-19 12:06:09.274 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-19 12:06:09.413 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-19 12:06:09.577 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-19 12:22:03.403 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2018-05-19 12:22:03.410 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'localmqtt'
2018-05-19 12:23:28.132 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items'
2018-05-19 12:23:51.134 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.items'
2018-05-19 12:23:51.361 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.items'
2018-05-19 12:24:13.891 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap'
2018-05-19 12:24:52.145 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.sitemap'
2018-05-19 12:24:52.235 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'test.sitemap'
2018-05-19 12:39:38.977 [ERROR] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to broker was lost
org.eclipse.paho.client.mqttv3.MqttException: Connection lost
	at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:146) [208:org.openhab.io.transport.mqtt:1.11.0]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.io.EOFException
	at java.io.DataInputStream.readByte(DataInputStream.java:267) ~[?:?]
	at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:65) ~[?:?]
	at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:107) ~[?:?]
	... 1 more
2018-05-19 12:39:39.029 [ERROR] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to 'localmqtt' was lost: Connection lost : ReasonCode 32109 : Cause : null
2018-05-19 12:39:39.033 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting connection helper to periodically try restore connection to broker 'localmqtt'
2018-05-19 12:39:41.505 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2018-05-19 12:39:49.041 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'localmqtt'
2018-05-19 12:40:00.020 [INFO ] [penhab.io.transport.mqtt.MqttService] - Stopping broker connection 'localmqtt'
2018-05-19 12:40:00.022 [INFO ] [penhab.io.transport.mqtt.MqttService] - Stopping broker connection 'localmqtt2'
2018-05-19 12:40:00.704 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2018-05-19 12:40:00.729 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2018-05-19 12:40:00.743 [INFO ] [er.internal.HomeBuilderDashboardTile] - Stopped Home Builder
2018-05-19 12:40:00.803 [INFO ] [.dashboard.internal.DashboardService] - Stopped dashboard
==> /var/log/openhab2/events.log <==
2018-05-19 12:02:07.876 [thome.event.ExtensionEvent] - Extension 'package-standard' has been installed.
2018-05-19 12:02:20.987 [thome.event.ExtensionEvent] - Extension 'ui-homebuilder' has been installed.
2018-05-19 12:02:21.005 [thome.event.ExtensionEvent] - Extension 'ui-basic' has been installed.
2018-05-19 12:02:21.007 [thome.event.ExtensionEvent] - Extension 'ui-habpanel' has been installed.
2018-05-19 12:02:21.009 [thome.event.ExtensionEvent] - Extension 'ui-paper' has been installed.
2018-05-19 12:19:12.323 [thome.event.ExtensionEvent] - Extension 'binding-mqtt1' has been installed.
2018-05-19 12:25:52.669 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
2018-05-19 12:25:52.724 [vent.ItemStateChangedEvent] - mqttsw1 changed from NULL to ON
2018-05-19 12:26:12.813 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
2018-05-19 12:26:12.854 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF
2018-05-19 12:35:22.128 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
2018-05-19 12:35:22.143 [vent.ItemStateChangedEvent] - mqttsw1 changed from OFF to ON
2018-05-19 12:35:23.609 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
2018-05-19 12:35:23.629 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF
==> /var/log/openhab2/openhab.log <==
2018-05-19 12:40:30.047 [INFO ] [er.internal.HomeBuilderDashboardTile] - Started Home Builder at /homebuilder
2018-05-19 12:40:31.132 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.1.179
2018-05-19 12:40:31.198 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Found multiple local interfaces - ignoring 192.168.1.179
2018-05-19 12:40:31.383 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at http://192.168.1.147:8080
2018-05-19 12:40:31.387 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at https://192.168.1.147:8443
2018-05-19 12:41:05.271 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.items'
2018-05-19 12:41:09.001 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-05-19 12:41:10.111 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'test.sitemap'
2018-05-19 12:41:12.703 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-05-19 12:41:12.823 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-05-19 12:41:12.948 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-05-19 12:41:14.047 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2018-05-19 12:41:14.050 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'localmqtt'
==> /var/log/openhab2/events.log <==
2018-05-19 12:46:26.620 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command ON
2018-05-19 12:46:26.673 [vent.ItemStateChangedEvent] - mqttsw1 changed from NULL to ON
2018-05-19 12:46:27.679 [ome.event.ItemCommandEvent] - Item 'mqttsw1' received command OFF
2018-05-19 12:46:27.692 [vent.ItemStateChangedEvent] - mqttsw1 changed from ON to OFF

mosquitto.log:

1526721969: New connection from ::1 on port 1883.
1526721969: New client connected from ::1 as mosqsub/4288-openHABian (c1, k60).
1526722771: Socket error on client mosqsub/4288-openHABian, disconnecting.
1526722778: Error in poll: Interrupted system call.
1526722778: mosquitto version 1.4.10 terminating
1526722806: mosquitto version 1.4.10 (build date Fri, 22 Dec 2017 08:19:25 +0000) starting
1526722806: Config loaded from /etc/mosquitto/mosquitto.conf.
1526722806: Opening ipv4 listen socket on port 1883.
1526722806: Opening ipv6 listen socket on port 1883.
1526722874: New connection from 127.0.0.1 on port 1883.

Command mosquitto_sub -t “#”: empty

Strange syntax, never seen this. Tested at my RPi:

pi@rpi3openhab:~ $ mosquitto_sub -t "#"
Error: Invalid subscription topic '"#"', are all '+' and '#' wildcards correct?

Use 'mosquitto_sub --help' to see usage.

Try

mosquitto_sub -v -t /#

instead.

Edit: okay, never mind, usual problem with wrong double quotes …

Okay, you already know about the config bug in openHAB, so that should not be the problem, too:

It bug if change data in mqtt.cfg.
When in mqtt.cfg write data once - then allright

Correct :+1:

I install mosquitto server 1.4.15a on the PC and resetting OpenHab to PCs MQTT.
And it work!
And mosquitto_sub -t "#" wrote:

ON
OFF
ON
OFF

And Swithes are toggled.

SO!
OpenHab not connecting to mosquitto, which installed on openhabian. And don’t display error messages about this.
Mosquitto ver 1.4.10.
How to solve?

As I’m using mosquitto in version 1.4.10 on the very same machine as openHAB2, I can’t confirm this issue.

Please also take a look at the configuration in karaf:

openhab-cli console
(password as set for openhab console - default is habopen)
openhab> config:edit org.openhab.mqtt
openhab> property-list

Maybe there is some garbage to delete (property-delete for each unwanted parameter, then config:update to store the changes.

No garbage.
And what OH version?