Mqtt binding stops unexpectedly

In openhab 2.3.0, I do feature:install openhab-binding-mqtt1.
It works for about 1 minute, as I can see because Lichtintensiteit_Woonkamer_P changed from 0 to 1.8749999. This value can only come from my mqtt server, because that is the only binding to Lichtintensiteit_Woonkamer_P. And then it is uninstalled (which is unwanted behaviour)!
Note: I have another karaf container running (that runs the mqtt server, a camel context to poll the light sensor and a pilight client to send/receive kaku 433 MHz signals.

Can anyone explain what is happening to the mqtt binding?

This is part of the logging:


21:19:00.040 [INFO ] [marthome.model.script.LightsOn_Sensor] - initialisationPhaseTimer is null
21:19:30.052 [INFO ] [marthome.model.script.LightsOn_Sensor] - initialisationPhaseTimer is null
21:19:31.591 [INFO ] [.server.session.ServerUserAuthService] - Session openhab@/127.0.0.1:52482 authenticated
21:20:00.056 [INFO ] [marthome.model.script.LightsOn_Sensor] - initialisationPhaseTimer is null
21:20:23.023 [INFO ] [.internal.service.FeaturesServiceImpl] - Adding features: openhab-binding-mqtt1/[1.12.0,1.12.0]
21:20:30.062 [INFO ] [marthome.model.script.LightsOn_Sensor] - initialisationPhaseTimer is null
21:20:34.240 [INFO ] [.internal.service.FeaturesServiceImpl] - Changes to perform:
21:20:34.245 [INFO ] [.internal.service.FeaturesServiceImpl] -   Region: root
21:20:34.248 [INFO ] [.internal.service.FeaturesServiceImpl] -     Bundles to install:
21:20:34.251 [INFO ] [.internal.service.FeaturesServiceImpl] -       mvn:org.openhab.binding/org.openhab.binding.mqtt/1.12.0
21:20:34.254 [INFO ] [.internal.service.FeaturesServiceImpl] -       mvn:org.openhab.io/org.openhab.io.transport.mqtt/1.12.0
21:20:34.261 [INFO ] [.internal.service.FeaturesServiceImpl] - Stopping bundles:
21:20:34.269 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.binding.hue/0.10.0.oh230
21:20:34.372 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0220:1:huelamp1' changed from ONLINE to UNINITIALIZED
21:20:34.409 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0220:1:huelamp1' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
21:20:34.425 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0220:1:huelamp2' changed from OFFLINE: Hue bridge reports light as not reachable. to UNINITIALIZED
21:20:34.441 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0220:1:huelamp2' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
21:20:34.461 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0220:1:huelamp3' changed from OFFLINE: Hue bridge reports light as not reachable. to UNINITIALIZED
21:20:34.471 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0220:1:huelamp3' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
21:20:34.479 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:bridge:1' changed from ONLINE to UNINITIALIZED
21:20:34.498 [INFO ] [smarthome.event.InboxRemovedEvent    ] - Discovery Result with UID 'hue:0220:1:2' has been removed.
21:20:34.509 [INFO ] [smarthome.event.InboxRemovedEvent    ] - Discovery Result with UID 'hue:0220:1:1' has been removed.
21:20:34.518 [INFO ] [smarthome.event.InboxRemovedEvent    ] - Discovery Result with UID 'hue:0220:1:3' has been removed.
21:20:34.595 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:bridge:1' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
21:20:34.640 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.optimize/0.10.0.oh230
21:20:34.667 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.mdns/0.10.0.oh230
21:20:42.713 [INFO ] [.internal.service.FeaturesServiceImpl] -   javax.ws.rs-api/2.0.1
21:20:42.763 [INFO ] [.internal.service.FeaturesServiceImpl] -   com.eclipsesource.jaxrs.publisher/5.3.1.201602281253
21:20:42.849 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15]]
21:20:42.902 [INFO ] [ice.jetty.internal.HttpServiceContext] - ServletContext service already removed
21:20:42.915 [INFO ] [e.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default]}
21:20:42.951 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.ui.habpanel/2.3.0
21:20:42.970 [INFO ] [bpanel.internal.HABPanelDashboardTile] - Stopped HABPanel
21:20:42.975 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [org.openhab.ui.habpanel_2.3.0 [206]]
21:20:42.986 [INFO ] [e.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [206], contextID=default]}
21:20:43.059 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.automation.rest/0.10.0.oh230
21:20:43.097 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.ui.iconset.classic/0.10.0.oh230
21:20:43.167 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.ui.icon/0.10.0.oh230
21:20:43.182 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149]]
21:20:43.197 [INFO ] [e.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149], contextID=default]}
21:20:43.216 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.sitemap/0.10.0.oh230
21:20:43.255 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.voice/0.10.0.oh230
21:20:43.277 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.sse/0.10.0.oh230
21:20:43.317 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.core/0.10.0.oh230
21:20:43.475 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest/0.10.0.oh230
21:20:43.508 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.core.id/0.10.0.oh230
21:20:43.524 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.media.jersey-media-sse/2.22.2
21:20:43.535 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.media.jersey-media-multipart/2.22.2
21:20:43.547 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.core.jersey-server/2.22.2
21:20:43.604 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.core.jersey-common/2.22.2
21:20:43.646 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.core.jersey-client/2.22.2
21:20:43.741 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.containers.jersey-container-servlet-core/2.22.2
21:20:43.758 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.containers.jersey-container-servlet/2.22.2
21:20:43.768 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.hk2.utils/2.4.0.b34
21:20:43.783 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.hk2.locator/2.4.0.b34
21:20:43.797 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.hk2.api/2.4.0.b34
21:20:43.840 [INFO ] [.internal.service.FeaturesServiceImpl] - Installing bundles:
21:20:43.843 [INFO ] [.internal.service.FeaturesServiceImpl] -   mvn:org.openhab.binding/org.openhab.binding.mqtt/1.12.0
21:20:43.892 [INFO ] [.internal.service.FeaturesServiceImpl] -   mvn:org.openhab.io/org.openhab.io.transport.mqtt/1.12.0
21:20:44.004 [INFO ] [.internal.service.FeaturesServiceImpl] - Refreshing bundles:
21:20:44.008 [INFO ] [.internal.service.FeaturesServiceImpl] -     com.eclipsesource.jaxrs.publisher/5.3.1.201602281253 (Wired to org.glassfish.jersey.core.jersey-common/2.22.2 which is being refreshed)
21:20:44.011 [INFO ] [.internal.service.FeaturesServiceImpl] -     javax.ws.rs-api/2.0.1 (Wired to org.glassfish.jersey.core.jersey-server/2.22.2 which is being refreshed)
21:20:44.014 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.automation.rest/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.018 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.core.id/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.021 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.024 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.core/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.026 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.mdns/0.10.0.oh230 (Wired to org.eclipse.smarthome.io.rest/0.10.0.oh230 which is being refreshed)
21:20:44.028 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.optimize/0.10.0.oh230 (Wired to com.eclipsesource.jaxrs.publisher/5.3.1.201602281253 which is being refreshed)
21:20:44.031 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.sitemap/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.033 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.sse/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.035 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.voice/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.038 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.ui.icon/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.040 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.ui.iconset.classic/0.10.0.oh230 (Wired to org.eclipse.smarthome.ui.icon/0.10.0.oh230 which is being refreshed)
21:20:44.043 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.hk2.api/2.4.0.b34 (Wired to org.glassfish.hk2.utils/2.4.0.b34 which is being refreshed)
21:20:44.046 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.hk2.locator/2.4.0.b34 (Wired to org.glassfish.hk2.api/2.4.0.b34 which is being refreshed)
21:20:44.049 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.hk2.utils/2.4.0.b34 (Should be wired to: org.eclipse.osgi/3.12.50.v20170928-1321 (through [org.glassfish.hk2.utils/2.4.0.b34] osgi.wiring.package; filter:="(osgi.wiring.package=javax.annotation)"))
21:20:44.051 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.containers.jersey-container-servlet/2.22.2 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.054 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.containers.jersey-container-servlet-core/2.22.2 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.056 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.core.jersey-client/2.22.2 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:44.059 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.core.jersey-common/2.22.2 (Wired to org.glassfish.hk2.utils/2.4.0.b34 which is being refreshed)
21:20:44.061 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.core.jersey-server/2.22.2 (Wired to org.glassfish.hk2.utils/2.4.0.b34 which is being refreshed)
21:20:44.063 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.media.jersey-media-multipart/2.22.2 (Wired to org.glassfish.jersey.core.jersey-common/2.22.2 which is being refreshed)
21:20:44.066 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.media.jersey-media-sse/2.22.2 (Wired to org.glassfish.jersey.core.jersey-common/2.22.2 which is being refreshed)
21:20:44.069 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.openhab.ui.habpanel/2.3.0 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:20:45.186 [INFO ] [.internal.service.FeaturesServiceImpl] - Removing features: feature:openhab-binding-mqtt1/[1.12.0,1.12.0]
21:20:46.525 [INFO ] [openhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
21:20:46.533 [INFO ] [rt.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'broker'
21:20:48.438 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.habpanel_2.3.0 [206]] to http service
21:20:48.485 [INFO ] [org.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
21:20:48.490 [INFO ] [ice.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [206], contextID=default], with context-name: 
21:20:48.505 [INFO ] [e.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [206], contextID=default]}
21:20:48.514 [INFO ] [bpanel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
21:20:48.675 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149]] to http service
21:20:48.700 [INFO ] [org.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
21:20:48.826 [INFO ] [ice.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149], contextID=default], with context-name: 
21:20:48.840 [INFO ] [e.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149], contextID=default]}
21:20:49.523 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Binding bundle: [com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15]] to http service
21:20:49.785 [INFO ] [org.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
21:20:49.791 [INFO ] [ice.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default], with context-name: 
21:20:49.809 [INFO ] [e.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default]}
21:20:50.380 [INFO ] [.internal.service.FeaturesServiceImpl] - Starting bundles:
21:20:50.391 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.binding.mqtt/1.12.0
21:20:50.753 [INFO ] [.internal.service.FeaturesServiceImpl] - Done.
21:21:00.077 [INFO ] [marthome.model.script.LightsOn_Sensor] - initialisationPhaseTimer is null
21:21:00.390 [INFO ] [smarthome.event.ItemStateChangedEvent] - LichtIntensiteit_Woonkamer_P changed from 0 to 1.8749999
21:21:00.715 [INFO ] [.internal.service.FeaturesServiceImpl] - Changes to perform:
21:21:00.719 [INFO ] [.internal.service.FeaturesServiceImpl] -   Region: root
21:21:00.722 [INFO ] [.internal.service.FeaturesServiceImpl] -     Bundles to uninstall:
21:21:00.725 [INFO ] [.internal.service.FeaturesServiceImpl] -       org.openhab.binding.mqtt/1.12.0
21:21:00.728 [INFO ] [.internal.service.FeaturesServiceImpl] -       org.openhab.io.transport.mqtt/1.12.0
21:21:00.732 [INFO ] [.internal.service.FeaturesServiceImpl] - Stopping bundles:
21:21:00.736 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.optimize/0.10.0.oh230
21:21:00.756 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.mdns/0.10.0.oh230
21:21:08.814 [INFO ] [.internal.service.FeaturesServiceImpl] -   javax.ws.rs-api/2.0.1
21:21:08.841 [INFO ] [.internal.service.FeaturesServiceImpl] -   com.eclipsesource.jaxrs.publisher/5.3.1.201602281253
21:21:09.051 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15]]
21:21:09.054 [INFO ] [ice.jetty.internal.HttpServiceContext] - ServletContext service already removed
21:21:09.065 [INFO ] [e.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default]}
21:21:09.082 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.binding.mqtt/1.12.0
21:21:09.199 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.io.transport.mqtt/1.12.0
21:21:09.209 [INFO ] [openhab.io.transport.mqtt.MqttService] - Stopping broker connection 'broker'
21:21:09.272 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.core.id/0.10.0.oh230
21:21:09.305 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.sitemap/0.10.0.oh230
21:21:09.361 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.core/0.10.0.oh230
21:21:09.570 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest/0.10.0.oh230
21:21:09.638 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.ui.habpanel/2.3.0
21:21:09.669 [INFO ] [bpanel.internal.HABPanelDashboardTile] - Stopped HABPanel
21:21:09.675 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [org.openhab.ui.habpanel_2.3.0 [206]]
21:21:09.693 [INFO ] [e.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [206], contextID=default]}
21:21:09.768 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.automation.rest/0.10.0.oh230
21:21:09.803 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.voice/0.10.0.oh230
21:21:09.820 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.ui.iconset.classic/0.10.0.oh230
21:21:09.885 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.ui.icon/0.10.0.oh230
21:21:09.896 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Unbinding bundle: [org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149]]
21:21:09.915 [INFO ] [e.jetty.server.handler.ContextHandler] - Stopped HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149], contextID=default]}
21:21:09.934 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.sse/0.10.0.oh230
21:21:09.963 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.media.jersey-media-sse/2.22.2
21:21:09.972 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.media.jersey-media-multipart/2.22.2
21:21:09.985 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.core.jersey-server/2.22.2
21:21:10.036 [INFO ] [smarthome.event.ItemStateChangedEvent] - LichtIntensiteit_Woonkamer changed from 0 to 1.8749999
21:21:10.047 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.core.jersey-common/2.22.2
21:21:10.087 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.core.jersey-client/2.22.2
21:21:10.103 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.containers.jersey-container-servlet-core/2.22.2
21:21:10.115 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.jersey.containers.jersey-container-servlet/2.22.2
21:21:10.123 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.hk2.utils/2.4.0.b34
21:21:10.137 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.hk2.locator/2.4.0.b34
21:21:10.151 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.glassfish.hk2.api/2.4.0.b34
21:21:10.170 [INFO ] [.internal.service.FeaturesServiceImpl] - Uninstalling bundles:
21:21:10.173 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.binding.mqtt/1.12.0
21:21:10.198 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.openhab.io.transport.mqtt/1.12.0
21:21:10.252 [INFO ] [.internal.service.FeaturesServiceImpl] - Refreshing bundles:
21:21:10.254 [INFO ] [.internal.service.FeaturesServiceImpl] -     com.eclipsesource.jaxrs.publisher/5.3.1.201602281253 (Wired to org.glassfish.jersey.core.jersey-common/2.22.2 which is being refreshed)
21:21:10.257 [INFO ] [.internal.service.FeaturesServiceImpl] -     javax.ws.rs-api/2.0.1 (Wired to org.glassfish.jersey.core.jersey-server/2.22.2 which is being refreshed)
21:21:10.259 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.automation.rest/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.262 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.core.id/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.264 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.268 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.core/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.271 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.mdns/0.10.0.oh230 (Wired to org.eclipse.smarthome.io.rest/0.10.0.oh230 which is being refreshed)
21:21:10.273 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.optimize/0.10.0.oh230 (Wired to com.eclipsesource.jaxrs.publisher/5.3.1.201602281253 which is being refreshed)
21:21:10.275 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.sitemap/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.277 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.sse/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.279 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.io.rest.voice/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.281 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.ui.icon/0.10.0.oh230 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.282 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.eclipse.smarthome.ui.iconset.classic/0.10.0.oh230 (Wired to org.eclipse.smarthome.ui.icon/0.10.0.oh230 which is being refreshed)
21:21:10.285 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.hk2.api/2.4.0.b34 (Wired to org.glassfish.hk2.utils/2.4.0.b34 which is being refreshed)
21:21:10.290 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.hk2.locator/2.4.0.b34 (Wired to org.glassfish.hk2.api/2.4.0.b34 which is being refreshed)
21:21:10.293 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.hk2.utils/2.4.0.b34 (Should be wired to: org.eclipse.osgi/3.12.50.v20170928-1321 (through [org.glassfish.hk2.utils/2.4.0.b34] osgi.wiring.package; filter:="(osgi.wiring.package=javax.annotation)"))
21:21:10.296 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.containers.jersey-container-servlet/2.22.2 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.300 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.containers.jersey-container-servlet-core/2.22.2 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.304 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.core.jersey-client/2.22.2 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:10.345 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.core.jersey-common/2.22.2 (Wired to org.glassfish.hk2.utils/2.4.0.b34 which is being refreshed)
21:21:10.350 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.core.jersey-server/2.22.2 (Wired to org.glassfish.hk2.utils/2.4.0.b34 which is being refreshed)
21:21:10.352 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.media.jersey-media-multipart/2.22.2 (Wired to org.glassfish.jersey.core.jersey-common/2.22.2 which is being refreshed)
21:21:10.355 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.glassfish.jersey.media.jersey-media-sse/2.22.2 (Wired to org.glassfish.jersey.core.jersey-common/2.22.2 which is being refreshed)
21:21:10.358 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.openhab.binding.mqtt/1.12.0 (Bundle will be uninstalled)
21:21:10.367 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.openhab.io.transport.mqtt/1.12.0 (Bundle will be uninstalled)
21:21:10.369 [INFO ] [.internal.service.FeaturesServiceImpl] -     org.openhab.ui.habpanel/2.3.0 (Wired to javax.ws.rs-api/2.0.1 which is being refreshed)
21:21:12.323 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Binding bundle: [com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15]] to http service
21:21:12.643 [INFO ] [org.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
21:21:12.649 [INFO ] [ice.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default], with context-name: 
21:21:12.665 [INFO ] [e.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [15], contextID=default]}
21:21:13.760 [ERROR] [org.eclipse.smarthome.io.rest.sse    ] - FrameworkEvent ERROR - org.eclipse.smarthome.io.rest.sse
org.osgi.framework.BundleException: Exception in org.eclipse.smarthome.io.rest.sse.internal.SseActivator.start() of bundle org.eclipse.smarthome.io.rest.sse.
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:800) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:729) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:933) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:309) [?:?]
	at org.eclipse.osgi.container.Module.doStart(Module.java:581) [?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:449) [?:?]
	at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:468) [?:?]
	at org.eclipse.osgi.container.ModuleContainer.start(ModuleContainer.java:750) [?:?]
	at org.eclipse.osgi.container.ModuleContainer.applyDelta(ModuleContainer.java:741) [?:?]
	at org.eclipse.osgi.container.ModuleContainer.resolveAndApply(ModuleContainer.java:511) [?:?]
	at org.eclipse.osgi.container.ModuleContainer.resolve(ModuleContainer.java:457) [?:?]
	at org.eclipse.osgi.container.ModuleContainer.refresh(ModuleContainer.java:1001) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerWiring.dispatchEvent(ModuleContainer.java:1382) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerWiring.dispatchEvent(ModuleContainer.java:1) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]
Caused by: java.lang.LinkageError: ClassCastException: attempting to castbundleresource://33.fwk10516733/javax/ws/rs/ext/RuntimeDelegate.class to bundleresource://33.fwk10516733/javax/ws/rs/ext/RuntimeDelegate.class
	at javax.ws.rs.ext.RuntimeDelegate.findDelegate(RuntimeDelegate.java:146) ~[?:?]
	at javax.ws.rs.ext.RuntimeDelegate.getInstance(RuntimeDelegate.java:120) ~[?:?]
	at javax.ws.rs.core.MediaType.valueOf(MediaType.java:179) ~[?:?]
	at org.glassfish.jersey.media.sse.SseFeature.<clinit>(SseFeature.java:62) ~[?:?]
	at org.eclipse.smarthome.io.rest.sse.internal.SseActivator.start(SseActivator.java:49) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:779) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:772) ~[?:?]
	... 15 more
21:21:13.886 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149]] to http service
21:21:13.905 [INFO ] [org.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
21:21:13.911 [INFO ] [ice.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149], contextID=default], with context-name: 
21:21:13.926 [INFO ] [e.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.eclipse.smarthome.ui.icon_0.10.0.oh230 [149], contextID=default]}
21:21:14.238 [INFO ] [rvice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.habpanel_2.3.0 [206]] to http service
21:21:14.265 [INFO ] [org.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
21:21:14.270 [INFO ] [ice.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [206], contextID=default], with context-name: 
21:21:14.285 [INFO ] [e.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.3.0 [206], contextID=default]}
21:21:14.294 [INFO ] [bpanel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
21:21:14.360 [INFO ] [.internal.service.FeaturesServiceImpl] - Starting bundles:
21:21:14.366 [INFO ] [.internal.service.FeaturesServiceImpl] -   org.eclipse.smarthome.io.rest.sse/0.10.0.oh230
21:21:30.070 [INFO ] [marthome.model.script.LightsOn_Sensor] - initialisationPhaseTimer is null

Do you have the MQTT Action installed as well? There apparently is still a bug hanging around where the two sometimes clash with each other. The solution is to uninstall and reinstall the MQTT Action.

I don’t have the MQTT Action installed. Should I install it?

openhab> feature:list|grep -i mqtt                                                                                                                                                                                                                    
esh-tp-paho                                 │ 0.10.0.oh230     │          │ Uninstalled │ distro-2.3.0                │ MQTT v3 Client
esh-io-transport-mqtt                       │ 0.10.0.oh230     │          │ Uninstalled │ distro-2.3.0                │
openhab-transport-mqtt                      │ 2.3.0            │          │ Uninstalled │ distro-2.3.0                │ MQTT Transport
esh-io-mqttembeddedbroker                   │ 0.10.0.oh230     │          │ Uninstalled │ openhab-addons-2.3.0        │ Embedded MQTT Broker
openhab-misc-mqttbroker                     │ 2.3.0            │          │ Uninstalled │ openhab-addons-2.3.0        │ Embedded MQTT Broker
openhab-action-mqtt                         │ 1.12.0           │          │ Uninstalled │ openhab-addons-2.3.0        │ MQTT Action
openhab-binding-mqtt1                       │ 1.12.0           │          │ Uninstalled │ openhab-addons-2.3.0        │ MQTT Binding
openhab-binding-mqttitude1                  │ 1.12.0           │          │ Uninstalled │ openhab-addons-2.3.0        │ OwnTracks (formerly MQTTitude) Binding
openhab-persistence-mqtt                    │ 1.12.0           │          │ Uninstalled │ openhab-addons-2.3.0        │ MQTT Persistence
openhab>                                                    

No, that isn’t your problem then. I can’t say I have much to offer. When ever something weird like this occurs the first thing to try is Clear the Cache.

Unfortunately that didn’t solve the problem. Maybe I have to focus on the BundleException?
Or try an openhab snapshot?

It’s always a good idea to try a snapshot. There might be a weird bug that got fixed. And my next solution would be to reinstall anyway so upgrading would kill two birds with one stone.

I don’t know what happened, but it is working now, without any repair action. I will just leave it that way for now, so I can continue with my interesting openhab project.
What I see in karaf is that the feature openhab-binding-mqtt1 is Uninstalled, but that there are two mqtt bundles that are installed (I don’t remember the exact osgi state, could be Active, I am not logged in at this very moment to verify) So that explains why it is working, but it does not explain why the feature is Uninstalled.
Anyway: thanks for your answers, it was a big support in the sense I didn’t feel being left alone with my problem!

Possibly the problem was that I could not install through Paper UI (mqtt is not listed there) and that I had not installed the compat1 binding.

I had lots of trouble with MQTT the last days. So when the MQTT binding unexpectedly stopped in my installation (which I observed at least three times, probably many times more), I always thought it might have been my fault.

But today it vanished without me changing something relevant. I’ll provide an excerpt from my log during startup:

2018-12-30 12:19:42.114 [WARN ] [r.internal.EmbeddedBrokerServiceImpl] - Embedded broker offline - Reason unknown
2018-12-30 12:19:42.250 [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'
2018-12-30 12:19:42.318 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-binding-mqtt'
2018-12-30 12:19:42.461 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker
2018-12-30 12:19:42.495 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=embedded-mqtt-broker
2018-12-30 12:19:43.053 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'LastMotion.rules'
2018-12-30 12:19:43.576 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key avmfritz:HAN_FUN_CONTACT:192_168_1_1:053330031905_1 in ManagedThingProvider, because it does not exists.
2018-12-30 12:19:46.519 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=sonoff-86DF27
2018-12-30 12:19:46.523 [WARN ] [moquette.spi.impl.SessionsRepository] - Session does not exist. CId=sonoff-86DF27

The broker is running fine all the time. It rarely made any problems for me. As opposed to the binding.

Cheers,
Michael

Just for the curios: The startup happended because I had OH down to make a backup, not because I changed something in the configuration.

And: The only thing needed to have everything running again is to re-install the binding in the paper ui. No need to change any config, restart/reboot/clear cache, restart broker or anything.

Do you by any chance have any modifications to addons.cfg? If so can you post the file here?

addons.cfg:

# The installation package of this openHAB instance
# Note: This is only regarded at the VERY FIRST START of openHAB
# Note: If you want to specify your add-ons yourself through entries below, set the package to "minimal"
# as otherwise your definition might be in conflict with what the installation package defines.
#
# Optional. If not set, the dashboard (https://<yourserver>:8080/) will ask you to choose a package.
#
# Valid options:
#   - minimal  : Installation only with dashboard, but no UIs or other add-ons. Use this for custom setups.
#   - simple   : Setup for using openHAB purely through UIs - you need to expect MANY constraints in functionality!
#   - standard : Default setup for normal users, best for textual setup
#   - expert   : Setup for expert users, especially for people migrating from openHAB 1.x
#   - demo     : A demo setup which includes UIs, a few bindings, config files etc.
#
# See https://www.openhab.org/docs/configuration/packages.html for a detailed explanation of these packages.
#
package = minimal

# Access Remote Add-on Repository
# Defines whether the remote openHAB add-on repository should be used for browsing and installing add-ons.
# This not only makes latest snapshots of add-ons available, it is also required for the installation of
# any legacy 1.x add-on. (default is true)
#
#remote = true

# Include legacy 1.x bindings. If set to true, it also allows the installation of 1.x bindings for which there is 
# already a 2.x version available (requires remote repo access, see above). (default is false)
#
legacy = true

# A comma-separated list of bindings to install (e.g. "binding = sonos,knx,zwave")
binding = amazonechocontrol,avmfritz,exec,expire1,fritzboxtr0641,homematic,lgwebos,netatmo,sonos,wol1

# A comma-separated list of UIs to install (e.g. "ui = basic,paper")
ui = basic,paper

# A comma-separated list of persistence services to install (e.g. "persistence = rrd4j,jpa")
persistence = mapdb

# A comma-separated list of actions to install (e.g. "action = mail,pushover")
action = pushover

# A comma-separated list of transformation services to install (e.g. "transformation = map,jsonpath")
transformation = map,regex

# A comma-separated list of voice services to install (e.g. "voice = marytts,freetts")
#voice = 

# A comma-separated list of miscellaneous services to install (e.g. "misc = myopenhab")
#misc = 

There are some things I’ve added, like mapdb.
Now that I look at it, it seems I’ve omitted the JSONPath transformation, which I enabled for Sonoff/Tasmota result mapping some days ago. Currently it is disabled. I hope that there are no inner workings of MQTT based on that.

BTW: I hope that it is ok to have some stuff (like MQTT-binding) enabled with paper ui, and some other stuff in the addons.cfg. Maybe with respect to MQTT I should have been a bit more consistent with my habit to use file based configuration and added that to the addons.cfg as well.

Cheers, Michael

Could you post which kind of broker and which version of mqtt binding you are using?
According the shown log you tried to start the embedded-mqtt-broker (which would come with the new mqtt2 binding), which failed, however you are stating “The broker is running fine all the time”, which sounds as if you are using a broker which is not emebedded.

I only use embedded broker and 2.4.0 binding. At least that is what I want to do. All the time the external components (Tasmota, iPhone, …) connect to the embedded broker just fine. When I deliberately change credentials of the embedded broker, the external connections fail (as expected), when I change it back again, everybody can connect again. This makes me quite sure that I am not using some other broken accidentally.

BTW: the last three days the whole system ran just fine, incl. the binding. But I didn’t change the binding or rebooted.

If you use addons.cfg to install any binding, you must use it to install ALL bindings. This file takes precedence over what you do in PaperUI. So append “mqtt” if you are trying to install the 2.4 version binding or “mqtt1” if you are trying to install the old 1.x version binding to the end of the list of the line that starts with "binding = ".

2 Likes

OK, that would explain the mess. Thank you for the clarification.
Cheers, Michael

So with the binding I am OK now. It is defined in addons.cfg and configured in thing files.
All seems to work fine and survive restart.

But with respect to the embedded broker I still miss something.
I now have the definition added to addons.cfg as well:

# A comma-separated list of miscellaneous services to install (e.g. "misc = myopenhab")
misc = mqttbroker

But the parameters are still defined in paper ui, e.g. Embedded broker username.

I understood that mqtt.cfg is not relevant anymore with the embedded broker.

Are there other means to configure the embedded broker? I want to isolate different users and introduce acl mechanisms. Any chance?

I don’t think the embedded broker exposes those sorts of parameters yet (if ever). For the short term at least you will want to use an external broker.

But I haven’t played much with the embedded broker. I could be wrong. Look in PaperUI for all the parameters that are available.

You may be right with the number of parameters exposed; I already configured those in paper ui.
But still there is the conflict that I have the broker service added in addons.cfg as well. I am not sure, if this “hurts”, as it did with the binding.

So is the embedded broker meant to be configured by file anyhow?
Or does it totally require paper ui?