[SOLVED] Embedded MQTT Broker problems. ( Unexpected exception while processing MQTT message. Closing Netty channel. )

RPI3
Openhab 2.4 completely fresh install from Openhabian image.

Hello.
Been trying to get the new embedded broker to work, but no luck. Whenever i try to connect to it with MQTTlens it gives me an error message. (Attached)
Seems to be something Im missing? I have read the “guide” atthe blog.

Can anyone please point me in the right direction? :slight_smile:

Log:

2018-12-28 17:47:58.226 [ERROR] [quette.server.netty.NettyMQTTHandler] - Unexpected exception while processing MQTT message. Closing Netty channel. CId=null

java.lang.NullPointerException: null

	at io.moquette.server.netty.metrics.MQTTMessageLogger.logMQTTMessage(MQTTMessageLogger.java:54) ~[199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.moquette.server.netty.metrics.MQTTMessageLogger.channelRead(MQTTMessageLogger.java:44) ~[199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.moquette.server.netty.metrics.MessageMetricsHandler.channelRead(MessageMetricsHandler.java:50) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:350) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.moquette.server.netty.metrics.BytesMetricsHandler.channelRead(BytesMetricsHandler.java:51) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:141) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [199:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

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

Found the fault right after i posted! :blush:

Seems like there is a limit is the length of the client id on the broker?

Changed it to “lens” from “lens_XZgURcuhb2cTy5Wf7rwLcbTKFQ4” and it works.

It still gives me a small warning in tail:

2018-12-28 18:05:23.621 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=lens
1 Like

I have created a bug report:

I get a similar exception, though my client Ids are quite short:

2018-12-29 14:35:01.705 [ERROR] [quette.server.netty.NettyMQTTHandler] - Unexpected exception while processing MQTT message. Closing Netty channel. CId=null
java.lang.NullPointerException: null
        at io.moquette.server.netty.metrics.MQTTMessageLogger.logMQTTMessage(MQTTMessageLogger.java:54) ~[219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.moquette.server.netty.metrics.MQTTMessageLogger.channelRead(MQTTMessageLogger.java:44) ~[219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.moquette.server.netty.metrics.MessageMetricsHandler.channelRead(MessageMetricsHandler.java:50) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:297) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:350) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:265) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.moquette.server.netty.metrics.BytesMetricsHandler.channelRead(BytesMetricsHandler.java:51) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:141) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [219:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]
        at java.lang.Thread.run(Thread.java:748) [?:?]

When I grep

grep "Session does" /var/log/openhab2/openhab.log

I get:

2018-12-29 13:44:08.965 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=paho58845852998318
2018-12-29 13:54:48.711 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=Michaels_Iphone
2018-12-29 13:54:48.711 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker
2018-12-29 13:54:48.741 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker
2018-12-29 13:54:48.749 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=Michaels_Iphone
2018-12-29 13:54:56.510 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 13:54:56.514 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:01:59.405 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:01:59.409 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:19:09.037 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker
2018-12-29 14:19:09.071 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker
2018-12-29 14:19:18.241 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:19:18.244 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:25:36.075 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:25:36.080 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:27:23.440 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=Michaels_Iphone
2018-12-29 14:27:23.451 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=Michaels_Iphone
2018-12-29 14:29:48.952 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:29:48.957 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:30:15.537 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27
2018-12-29 14:30:15.542 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=DVES_86DF27

Now this is funny, as:

DVES_86DF27 is mv S20 switch, Michaels_Iphone is an app I use to debug, embedded-mqtt-broker comes from OH2, paho58845852998318 comes from OH2 as well.

This is funny, why two connections from OH2?

My Bridge thing uses:

Bridge mqtt:broker:MosquittoMqttBroker "Mosquitto MQTT Broker" @ "MQTT" [ 
  host="192.168.1.168",
  secure=false,
  port=1883,
  qos=0,
  retain=false,
  //clientid="Oh2Mqtt2Thing",  
  clientid="Oh2Mqtt",
  //certificate="",
  //certificatepin=false,

and I tried to make the clientid shorter already. But that ID does not show up and my binding dies not work anymore. It worked before, and I just changed the topic.

Cheers

This is alright. There is one connection for maintenance and one connection per defined Broker Thing.
I have to admit, it would be smarter to change the client ids from “paho…” to the broker Thing IDs.

It may help if we just update the internal broker to version 0.11 (currently 0.10). You have the option of using an external broker like mosquitto for now if specific messages don’t work.

I am not convinced that messages are my problem. At any time I can use my Sonoff switch and an iPhone with an MQTT app to switch on/off. All with the embedded broker.

And even got this working for a few minutes with the oh binding. But then I changed the topic names and couldn’t get it back to work. Even though the switching with the iPhone still works. And the binding could just consume the messages to reflect the current state, but even that does not work.

I suspect some other strange effect based on my configuration. Depending on the order in which I set up things the MQTT connections of oh sometimes use 127.0.0.1 instead of 192.168.1.168. And the internal files generated somewhere under /var/lib/openhab2 sometimes contain garbage. like “1883.0” as port number or lines beginning with a suffix of my password.

Under configuration/services I see two services:

  • MQTT Embedded Broker
  • MQTT System Broker Connection

I can only “configure” the former.
The later has just a “manage” link. That gets me to an empty screen with the plus (+). If I press the plus, I obtain a white box with Configure MQTT system broker connection org.eclipse.smarthome.mqttbroker

Beside the EXPERT settings, there is just a CANCEL and SAVE. When I “SAVE”, it tells me “service config updated”. Once I tried to enter key/value pairs in the EXPERT mode. Some of this ended up in the files under /var/lib/openhab2. So maybe I spoiled it myself.

But trying to delete caches etc and rebooting didn’t heal. Somehow I am stuck. According to the documentation or at least according to what I understood, at some point, something would have to have appeared in my inbox. but that never happened.

[offtopic: My other configuration is very file-driven. I have to admit that I do not like to rely on the repeatability of the internal storage and mechanism of paper ui very much and like to have everything in a way I can save and copy to my git…]

But with MQTT I fail to see what is missing. Maybe there is a better way to debug? Some categories and package prefixes to set to be more verbose?

Any help appreciated.

Cheers,
Michael

OK, it took me some time to get it working again and resolve the mess.
What I did:

  • Uninstall MQTT Binding
  • Uninstall MQTT Embedded Broker
  • stop Openhab
  • remove cache etc.
  • start Openhab
  • Install and configure embedded Broker
  • Install MQTT Binding
  • Deploy Bridge thing, generic mqtt thing and items in three different files

What was new (as compared to previous attempts): I uninstalledservices and bindings before cleaning cache.

Hope it stays alive, thank you for your support and attention,
Michael

1 Like

Never, never do that. This defines broker connections as well (“system broker connections”), but there is a bug somewhere in the framework. They do not appear anywhere and are absolutely garbage configured, but they are there and mess with anything else. Like old mqtt.cfg shadow entries, back in the day.

Resetting the cache was the right thing to do, if you accidentally clicked on the “+” and “save” button.

Reasonable. You should just know that Paper UI writes its config also to a human readable (json encoded) file, which can be backuped. The more appealing reason is: Copy & Paste, I think.

Unfortunately I got the mess back again when trying to clean up all kind of temporary names for users, topics and such.

I changed the username. For the embedded broker that went fine. S20 and iPhone use the new name and work. But the binding is down again. There seem to be two competing things: When I update the broker service, it puts a new Broker connection to my inbox. But when I try to accept it, it reports a conflict and fails.

And I changed the bridge.things file to reflect the new username. For that I get an according connection to the broker visible in the log (it has the distinct client it “openhab2”).

Time to re-install everything again just for a change of the user name? A single “init 6” didn’t do the trick…

Cheers,
Michael

Re-Installing just the binding worked. It put a new

MQTT Broker
System MQTT Broker
embedded-mqtt-broker

in my inbox, which I ignored for the time being.

Cheers.

Hm. That should not happen. That is clearly a bug. (Could you open a report on Github with all steps to reproduce it, please).

You don’t need to reinstall. There is nothing magical happening on a reinstall. It just removes the “jar” file.
You can also just restart the mqtt and mqtt-transport bundle in the openhab console.

I suspect that not the mqtt binding is behaving odd, it is the mqtt-transport bundle. Ok, that makes no difference for a user, but the developer is more happy with a suspect, I guess :slight_smile:

Maybe my initial description was not correct and the new connection appeared in the inbox a bit later, when re-installed the binding.

But the last time I did only re-install the binding, not the broker. So would that be the expected time where something might appear in my inbox?

Hmmm. I did never restart individual bundles. Maybe I should try.

But after all this struggling I’d rather try to improve my backup. I fear that the SD card might fail at any time. And the raspberry-setup is quite complex, as beside oh2 it has an embedded https reverse proxy server with certificates and scripting to poll bluetooth devices for presence detection. Bitwise backup has failed because the other 32GB cards I have differ slightly in size. And when I use Paragon to fit the partions and file systems, it is not aware of the linux boot mechanisms and fails.But I already found some longer posts in this forum…

Cheers
Michael

A have been working on getting a test sensor up and running with the embedded broker and the newly supported Home Convention.
It is working, but with some strange behavior… I send messages from the sensor every 3 seconds, and at that rate the RPI the processing takes ~25% cpu-time (htop). :open_mouth:
And it crashes the broker after a few hours. Below is a log from last nigh showing the behavior.

2018-12-31 02:23:35.413 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.20

2018-12-31 02:23:36.083 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:23:37.457 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.60 to 51.70

2018-12-31 02:23:40.353 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:23:40.850 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 17.70

2018-12-31 02:23:43.645 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.50

2018-12-31 02:23:44.629 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:23:46.102 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.70 to 18.60

2018-12-31 02:23:49.245 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.50 to 51.90

2018-12-31 02:23:49.371 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:23:52.137 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.60 to 18.20

2018-12-31 02:23:52.995 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:23:54.626 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 51.70

2018-12-31 02:23:57.558 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:01.590 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:06.621 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:10.606 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:14.480 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:18.902 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:20.560 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.80

2018-12-31 02:24:23.612 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:27.974 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:30.710 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.70

2018-12-31 02:24:32.095 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:36.301 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:40.220 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:44.520 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:46.523 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.80

2018-12-31 02:24:49.010 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:49.285 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 17.90

2018-12-31 02:24:51.847 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.70

2018-12-31 02:24:53.801 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:24:55.158 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.90 to 18.20

2018-12-31 02:24:57.821 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:02.207 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:02.745 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:03.574 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.80

2018-12-31 02:25:06.525 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:08.783 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.70

2018-12-31 02:25:10.506 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:15.072 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:19.125 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:23.820 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:25.204 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.80

2018-12-31 02:25:27.686 [me.event.ThingUpdatedEvent] - Thing 'mqtt:homie300:embedded-mqtt-broker:gromatic' has been updated.

2018-12-31 02:25:31.055 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.70

2018-12-31 02:25:32.156 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.80

2018-12-31 02:25:32.159 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 17.90

2018-12-31 02:25:32.164 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.70

2018-12-31 02:25:32.168 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.90 to 17.80

2018-12-31 02:25:32.172 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.60

2018-12-31 02:25:32.176 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.80 to 18.10

2018-12-31 02:25:32.180 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.60 to 51.80

2018-12-31 02:25:32.183 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.20

2018-12-31 02:25:32.187 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.70

2018-12-31 02:25:32.193 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 52.00

2018-12-31 02:25:32.196 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.70 to 17.50

2018-12-31 02:25:32.200 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 51.50

2018-12-31 02:25:32.203 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.50 to 18.00

2018-12-31 02:25:32.207 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.50 to 51.70

2018-12-31 02:25:32.210 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.20

2018-12-31 02:25:32.214 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.80

2018-12-31 02:25:32.219 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.224 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.20

2018-12-31 02:25:32.229 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 17.60

2018-12-31 02:25:32.233 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.50

2018-12-31 02:25:32.237 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.60 to 18.20

2018-12-31 02:25:32.241 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.50 to 51.90

2018-12-31 02:25:32.245 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.70

2018-12-31 02:25:32.250 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.10

2018-12-31 02:25:32.254 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.70 to 18.20

2018-12-31 02:25:32.258 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.80

2018-12-31 02:25:32.262 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.90

2018-12-31 02:25:32.266 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 51.80

2018-12-31 02:25:32.270 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.50

2018-12-31 02:25:32.275 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 52.10

2018-12-31 02:25:32.279 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.50 to 18.20

2018-12-31 02:25:32.283 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.80

2018-12-31 02:25:32.286 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.290 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.90

2018-12-31 02:25:32.294 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 51.80

2018-12-31 02:25:32.298 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.70

2018-12-31 02:25:32.302 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 52.10

2018-12-31 02:25:32.305 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.70 to 18.10

2018-12-31 02:25:32.308 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.80

2018-12-31 02:25:32.312 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 51.90

2018-12-31 02:25:32.315 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.319 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 51.70

2018-12-31 02:25:32.321 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.20

2018-12-31 02:25:32.325 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 51.90

2018-12-31 02:25:32.328 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.332 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.20

2018-12-31 02:25:32.335 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.338 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.20

2018-12-31 02:25:32.341 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.345 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.20

2018-12-31 02:25:32.348 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.351 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.50

2018-12-31 02:25:32.354 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.10

2018-12-31 02:25:32.361 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.50 to 17.60

2018-12-31 02:25:32.364 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.60

2018-12-31 02:25:32.370 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.60 to 18.80

2018-12-31 02:25:32.373 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.60 to 52.20

2018-12-31 02:25:32.376 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.80 to 18.60

2018-12-31 02:25:32.379 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.00

2018-12-31 02:25:32.383 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.60 to 18.10

2018-12-31 02:25:32.386 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 51.90

2018-12-31 02:25:32.390 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.00

2018-12-31 02:25:32.394 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 17.70

2018-12-31 02:25:32.398 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 51.80

2018-12-31 02:25:32.401 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.70 to 18.30

2018-12-31 02:25:32.405 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 52.10

2018-12-31 02:25:32.409 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.30 to 18.50

2018-12-31 02:25:32.412 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.00

2018-12-31 02:25:32.416 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.50 to 18.10

2018-12-31 02:25:32.420 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 17.90

2018-12-31 02:25:32.423 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 51.90

2018-12-31 02:25:32.427 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.90 to 18.10

2018-12-31 02:25:32.430 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.00

2018-12-31 02:25:32.434 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 51.90

2018-12-31 02:25:32.437 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.00

2018-12-31 02:25:32.440 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 52.10

2018-12-31 02:25:32.443 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.00

2018-12-31 02:25:32.447 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 17.50

2018-12-31 02:25:32.452 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 51.80

2018-12-31 02:25:32.456 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.50 to 18.10

2018-12-31 02:25:32.460 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.80 to 52.00

2018-12-31 02:25:32.464 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 52.10

2018-12-31 02:25:32.468 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 17.60

2018-12-31 02:25:32.472 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.70

2018-12-31 02:25:32.476 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.60 to 18.10

2018-12-31 02:25:32.480 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 52.10

2018-12-31 02:25:32.484 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.00

2018-12-31 02:25:32.488 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 52.10

2018-12-31 02:25:32.492 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 17.80

2018-12-31 02:25:32.495 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.90

2018-12-31 02:25:32.499 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.80 to 18.10

2018-12-31 02:25:32.503 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.10

2018-12-31 02:25:32.507 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.509 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.513 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 17.90

2018-12-31 02:25:32.516 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.00

2018-12-31 02:25:32.519 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.90 to 18.10

2018-12-31 02:25:32.522 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 52.10

2018-12-31 02:25:32.526 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.30

2018-12-31 02:25:32.529 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.532 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.30 to 18.10

2018-12-31 02:25:32.535 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.539 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.542 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.545 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.548 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.10

2018-12-31 02:25:32.552 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.554 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.50

2018-12-31 02:25:32.558 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.30

2018-12-31 02:25:32.561 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.50 to 18.10

2018-12-31 02:25:32.564 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.30 to 52.20

2018-12-31 02:25:32.567 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.570 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.20

2018-12-31 02:25:32.573 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.20 to 18.10

2018-12-31 02:25:32.577 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.580 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.584 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.586 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 17.50

2018-12-31 02:25:32.590 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.90

2018-12-31 02:25:32.593 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.50 to 18.00

2018-12-31 02:25:32.596 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.90 to 52.00

2018-12-31 02:25:32.599 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.10

2018-12-31 02:25:32.603 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 52.20

2018-12-31 02:25:32.605 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.609 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.612 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.30

2018-12-31 02:25:32.615 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.30 to 18.00

2018-12-31 02:25:32.618 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.10

2018-12-31 02:25:32.622 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.625 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.628 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.633 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.50

2018-12-31 02:25:32.636 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.40

2018-12-31 02:25:32.640 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.50 to 18.00

2018-12-31 02:25:32.643 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.40 to 52.10

2018-12-31 02:25:32.646 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 17.40

2018-12-31 02:25:32.649 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 51.70

2018-12-31 02:25:32.653 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.40 to 18.10

2018-12-31 02:25:32.657 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 51.70 to 52.30

2018-12-31 02:25:32.660 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.663 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.30 to 52.10

2018-12-31 02:25:32.666 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.669 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.10

2018-12-31 02:25:32.672 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.676 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.10

2018-12-31 02:25:32.679 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.10 to 52.20

2018-12-31 02:25:32.682 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 18.10

2018-12-31 02:25:32.685 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.30

2018-12-31 02:25:32.689 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.10 to 18.00

2018-12-31 02:25:32.691 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.30 to 52.20

2018-12-31 02:25:32.697 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 18.00 to 17.50

2018-12-31 02:25:32.700 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.20 to 52.00

2018-12-31 02:25:32.704 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Temperature changed from 17.50 to 18.00

2018-12-31 02:25:32.707 [vent.ItemStateChangedEvent] - Gromatic_Sensor_Humidity changed from 52.00 to 52.20

Sorry about the length :slight_smile: One can see that nearing the end many requests are being registered in under one second. Very strange.

I noticed this behavior before going to bed also, but a restart of the openhab installation was made.
The strange thing is that before restarting I unplugged power from the sensor, and I could still see new values being registered for several minutes.

Seems to me that maybe there is a buildup of messages over time that cause these problems?

Hi folks. I’ve been trying to get OpenHab 2.4 working on my Raspberry Pi 3. It seems to more or less operate as expected with the exception of MQTT message handling. I found some code for the ESP8266’s I want to use in remote switches and sensors I’m building, and am trying to use that to send messages through MQTT. I started getting this error after I’d been hacking around at OH for a while, so last night I nuked it and started with a fresh image of the latest stable build. The same thing is happening. I’m a little hazy on MQTT; do I need to address the messages to a particular server instance on OpenHab, or can I just use a topic and the IP of the Pi? I don’t think the client name has to be created on the server anywhere, does it? I just used the MQTT login name and password that I set up in the server menu. Here’s the message I get from tail -f:

2019-02-24 09:49:22.010 [ERROR] [quette.server.netty.NettyMQTTHandler] - Unexpected exception while processing MQTT message. Closing Netty channel. CId=ESP8266Client

java.io.IOException: Connection reset by peer

	at sun.nio.ch.FileDispatcherImpl.read0(Native Method) ~[?:?]

	at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) ~[?:?]

	at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) ~[?:?]

	at sun.nio.ch.IOUtil.read(IOUtil.java:192) ~[?:?]

	at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380) ~[?:?]

	at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288) ~[203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1108) ~[203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:345) ~[203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:126) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:645) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:580) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:497) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:459) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:886) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [203:org.eclipse.smarthome.io.mqttembeddedbroker:0.10.0.oh240]

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

and here’s the code I’m running on the ESP8266:

#include <WiFiClient.h>
#include <ESP8266WiFi.h>
#include <PubSubClient.h>
const char* ssid = "asdfgh";
const char* password =  "zxcvbn";
const char* mqttServer = "192.168.1.216";
const int mqttPort =1883;
const char* mqttUser = "mqtt";
const char* mqttPassword = "mqtt";
WiFiClient espClient;
PubSubClient client(espClient);
void setup()
{
  Serial.begin(115200);
  WiFi.begin(ssid, password);
  while (WiFi.status() != WL_CONNECTED) {
    delay(500);
    Serial.println("Connecting to WiFi..");
  }
  Serial.println("Connected to the WiFi network");
  client.setServer(mqttServer, mqttPort);
  client.setCallback(callback);
  while (!client.connected()) {
    Serial.println("Connecting to MQTT...");
    if(client.connect("ESP8266Client", mqttUser, mqttPassword )) 
{
     Serial.println("connected");
    }else{
      Serial.print("failed with state ");
      Serial.print(client.state());
      delay(2000);
    }
  }
  client.publish("esp8266test","Hello ESP World");
  client.subscribe("esp8266test");// here is where you later add a wildcard
}
void callback(char* topic, byte* payload, unsigned int length)
{
  Serial.print("Message arrived in topic: ");
  Serial.println(topic);
  Serial.print("Message:");
  for(int i = 0; i < length; i++) {
    Serial.print((char)payload[i]);
  }
  Serial.println();
}
void loop()
{
  client.loop();
}```


The ESP8266 serial monitor shows:  

Connecting to WiFi..
21:53:08.328 -> Connected to the WiFi network
21:53:08.328 -> Connecting to MQTT...
connected

and that's where it sits.  If I hit the reset button on the ESP8266, the same thing happens again on both ends.  Any suggestions?  I'm kinda stuck.

-Bill

The embedded broker will receive an update end of this month (so available with OH2.5M2 or OH2.5 later on). For now it does not support authentication correctly, is very verbosely logging and has issues with certain types of topics

Regarding your code: You should also check with another broker (mosquitto or a cloud mqtt broker). I suspect that your uC is closing the TCP session for whatever reason. Maybe you are not allowed to “Publish” before the main loop has started or so.

Okay - thanks. I’ll test the code. At the moment, I’ve just uninstalled the embedded broker via Paper and then installed Eclipse Mosquitto via the Openhabian installation menu. Am I correct in thinking that the MQTT binding will waves hands automagically detect the Eclips Mosquitto broker and communicate with it more hand waving somehow?

Unfortunately not, MQTT brokers can’t be auto-discovered, there is no standard yet. You need to add an MQTT broker Thing that points to your mosquitto.

So… I removed the mosquitto broker I’d installed and put back the embedded one, and now the mqtt binding sees the broker again, but it’s still logging errors and/or blowing up when I connect to it. Using the ESP8266 code I posted earlier, I was able to publish, subscribe, and receive messages via the mqtt test server (“test.mosquitto.org”), so I think that bit is working. I still see the “session does not exist CId=” messages (Google offered: Swords of El Cid: “Rodrigo! May God curse him!” - thanks Google). Can you explain to me what a “session” is with regard to MQTT? I seem to see the “CId=<whatever client name I used in client.connect(“ESP”, mqttUser, mqttPassword )> - in this case it would say “CId=ESP”. But that’s the client name, right? I found a page talking about a “Clean session=true/false” option in Mosquitto but I don’t know if that’s relevant. I tried no client name (session name?) at all and it shrieks, " [ERROR] [.moquette.spi.impl.ProtocolProcessor] - The MQTT client ID cannot be empty. Username=null”. From what I saw on the test.mosquitto.org server, that seems to be allowed, but the embedded server is having none of it.

I just restarted the Pi, and in the log I see:

2019-02-24 16:03:14.823 [hingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from UNINITIALIZED to INITIALIZING

2019-02-24 16:03:14.904 [hingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from INITIALIZING to OFFLINE (CONFIGURATION_ERROR): The system connection with the name embedded-mqtt-broker doesnt exist anymore.

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

2019-02-24 16:03:16.268 [WARN ] [r.internal.EmbeddedBrokerServiceImpl] - Embedded broker offline - Reason unknown

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

2019-02-24 16:03:16.291 [hingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from OFFLINE (CONFIGURATION_ERROR): The system connection with the name embedded-mqtt-broker doesnt exist anymore. to OFFLINE

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

2019-02-24 16:03:16.511 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to '127.0.0.1' with clientid embedded-mqtt-broker and file store '/var/lib/openhab2/mqtt/127.0.0.1'

2019-02-24 16:03:16.721 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker

2019-02-24 16:03:16.751 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker

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

2019-02-24 16:03:16.797 [hingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from OFFLINE to ONLINE

I’m not sure what to make of that. First it says it doesn’t exist anymore, then it refers to the name of the embedded broker as a session, but says it’s offline because the session does not exist, and finally that it’s online. Does any of this make any more sense to you than it does to me…? :worried:

I accidentally figured something out tonight. I had been watching the tail log page expecting it to show when a message was received, but all it ever showed was things like, “2019-02-25 19:41:11.829 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=booger” when I tried to send a message from a device. Just for the hell of it, I went into Paper UI and added a “publish trigger” with the same name as the topic my device was publishing to, and had the device send the same message to that topic again. Lo and behold, it shows up now as, “2019-02-25 19:42:50.963 [vent.ChannelTriggeredEvent] - mqtt:systemBroker:embedded-mqtt-broker:testchannel triggered 1” and doesn’t complain about the CId either. I was under the impression that devices could create topics on the fly and other devices could subscribe to them, and that the MQTT broker just passed things back and forth, but for whatever reason, it needed to have a publish trigger defined for it to work. Meh.