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