[SOLVED] MQTT Broker Moquette offline after upgrade to 2.5M3

  • Platform information:
    • Hardware: Dell desktop I3 8 Gbs RAM 1Tb HDD
    • OS: Debian 9
    • openHAB version: 2.5M3

After an upgrade to 2.5M3 from 2.4 stable my embedded MQTT broker is offline. Several restarts of OpenHAB and uninstall and reinstall broker does not seem to help. Most recent attempt at getting it going again has been to uninstall MQTT Broker Moquette using paper UI, restart OpenHAB then reinstall MQTT Broker Moquette
resulted in this in log:

18:35:06.527 [ERROR] [org.openhab.io.mqttembeddedbroker    ] - bundle org.openhab.io.mqttembeddedbroker:2.5.0.M3 (321)[org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService(365)] : The activate method has thrown an exception
java.lang.IllegalArgumentException: Could not deserialize [-84, -19, 0, 5, 115, 114, 0, 45, 105, 111, 46, 109, 111, 113, 117, 101, 116, 116, 101, 46, 98, 114, 111, 107, 101, 114, 46, 115, 117, 98, 115, 99, 114, 105, 112, 116, 105, 111, 110, 115, 46, 83, 117, 98, 115, 99, 114, 105, 112, 116, 105, 111, 110, -47, 11, -117, 54, 80, -6, 26, -58, 2, 0, 3, 76, 0, 8, 99, 108, 105, 101, 110, 116, 73, 100, 116, 0, 18, 76, 106, 97, 118, 97, 47, 108, 97, 110, 103, 47, 83, 116, 114, 105, 110, 103, 59, 76, 0, 12, 114, 101, 113, 117, 101, 115, 116, 101, 100, 81, 111, 115, 116, 0, 37, 76, 105, 111, 47, 110, 101, 116, 116, 121, 47, 104, 97, 110, 100, 108, 101, 114, 47, 99, 111, 100, 101, 99, 47, 109, 113, 116, 116, 47, 77, 113, 116, 116, 81, 111, 83, 59, 76, 0, 11, 116, 111, 112, 105, 99, 70, 105, 108, 116, 101, 114, 116, 0, 40, 76, 105, 111, 47, 109, 111, 113, 117, 101, 116, 116, 101, 47, 98, 114, 111, 107, 101, 114, 47, 115, 117, 98, 115, 99, 114, 105, 112, 116, 105, 111, 110, 115, 47, 84, 111, 112, 105, 99, 59, 120, 112, 116, 0, 20, 101, 109, 98, 101, 100,... [1.4.199/0]
	at org.h2.mvstore.DataUtils.newIllegalArgumentException(DataUtils.java:857) ~[?:?]
	at org.h2.mvstore.type.ObjectDataType.deserialize(ObjectDataType.java:376) ~[?:?]
	at org.h2.mvstore.type.ObjectDataType$SerializedObjectType.read(ObjectDataType.java:1547) ~[?:?]
	at org.h2.mvstore.type.ObjectDataType.read(ObjectDataType.java:231) ~[?:?]
	at org.h2.mvstore.type.ObjectDataType.read(ObjectDataType.java:114) ~[?:?]
	at org.h2.mvstore.Page$Leaf.readPayLoad(Page.java:1551) ~[?:?]
	at org.h2.mvstore.Page.read(Page.java:695) ~[?:?]
	at org.h2.mvstore.Page.read(Page.java:238) ~[?:?]
	at org.h2.mvstore.MVStore.readPage(MVStore.java:2187) ~[?:?]
	at org.h2.mvstore.MVMap.readPage(MVMap.java:554) ~[?:?]
	at org.h2.mvstore.MVMap.readOrCreateRootPage(MVMap.java:570) ~[?:?]
	at org.h2.mvstore.MVMap.setRootPos(MVMap.java:564) ~[?:?]
	at org.h2.mvstore.MVStore.openMap(MVStore.java:548) ~[?:?]
	at org.h2.mvstore.MVStore.openMap(MVStore.java:507) ~[?:?]
	at org.h2.mvstore.MVStore.openMap(MVStore.java:488) ~[?:?]
	at io.moquette.persistence.H2SubscriptionsRepository.<init>(H2SubscriptionsRepository.java:22) ~[?:?]
	at io.moquette.persistence.H2Builder.subscriptionsRepository(H2Builder.java:51) ~[?:?]
	at io.moquette.broker.Server.startServer(Server.java:167) ~[?:?]
	at org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService.startEmbeddedServer(EmbeddedBrokerService.java:310) ~[?:?]
	at org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService.initialize(EmbeddedBrokerService.java:195) ~[?:?]
	at org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService.activate(EmbeddedBrokerService.java:159) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invokeMethod(BaseMethod.java:228) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.access$500(BaseMethod.java:41) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod$Resolved.invoke(BaseMethod.java:664) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invoke(BaseMethod.java:510) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:317) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:307) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:340) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:114) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:982) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:955) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:900) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:906) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:402) ~[?:?]
	at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:165) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1153) ~[?:?]
	at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:1036) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1062) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:998) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.ClassNotFoundException: io.moquette.broker.subscriptions.Subscription cannot be found by com.h2database.mvstore_1.4.199
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:484) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) ~[?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) ~[?:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:?]
	at java.lang.Class.forName0(Native Method) ~[?:?]
	at java.lang.Class.forName(Class.java:348) ~[?:?]
	at java.io.ObjectInputStream.resolveClass(ObjectInputStream.java:686) ~[?:?]
	at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1868) ~[?:?]
	at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1751) ~[?:?]
	at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2042) ~[?:?]
	at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1573) ~[?:?]
	at java.io.ObjectInputStream.readObject(ObjectInputStream.java:431) ~[?:?]
	at org.h2.mvstore.type.ObjectDataType.deserialize(ObjectDataType.java:374) ~[?:?]
	... 96 more
18:35:06.591 [WARN ] [org.openhab.io.mqttembeddedbroker    ] - FrameworkEvent WARNING - org.openhab.io.mqttembeddedbroker
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:906) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:402) ~[?:?]
	at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:165) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1153) ~[?:?]
	at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:1036) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1062) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:998) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:?]
	at java.lang.Thread.run(Thread.java:748) ~[?:?]
18:35:06.595 [INFO ] [broker.internal.EmbeddedBrokerService] - Broker persistence file: mqttembedded.bin
18:35:06.639 [ERROR] [org.openhab.io.mqttembeddedbroker    ] - bundle org.openhab.io.mqttembeddedbroker:2.5.0.M3 (321)[org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService(365)] : The activate method has thrown an exception
java.lang.IllegalStateException: The file is locked: nio:/var/lib/openhab2/mqttembedded.bin [1.4.199/7]
	at org.h2.mvstore.DataUtils.newIllegalStateException(DataUtils.java:883) ~[?:?]
	at org.h2.mvstore.FileStore.open(FileStore.java:166) ~[?:?]
	at org.h2.mvstore.MVStore.<init>(MVStore.java:390) ~[?:?]
	at org.h2.mvstore.MVStore$Builder.open(MVStore.java:3343) ~[?:?]
	at io.moquette.persistence.H2Builder.initStore(H2Builder.java:40) ~[?:?]
	at io.moquette.broker.Server.startServer(Server.java:166) ~[?:?]
	at org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService.startEmbeddedServer(EmbeddedBrokerService.java:310) ~[?:?]
	at org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService.initialize(EmbeddedBrokerService.java:195) ~[?:?]
	at org.openhab.io.mqttembeddedbroker.internal.EmbeddedBrokerService.activate(EmbeddedBrokerService.java:159) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invokeMethod(BaseMethod.java:228) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.access$500(BaseMethod.java:41) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod$Resolved.invoke(BaseMethod.java:664) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invoke(BaseMethod.java:510) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:317) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:307) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:340) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:114) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:982) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:955) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:756) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:402) ~[?:?]
	at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:165) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1153) ~[?:?]
	at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:1036) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1062) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:998) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.nio.channels.OverlappingFileLockException
	at sun.nio.ch.SharedFileLockTable.checkList(FileLockTable.java:255) ~[?:?]
	at sun.nio.ch.SharedFileLockTable.add(FileLockTable.java:152) ~[?:?]
	at sun.nio.ch.FileChannelImpl.tryLock(FileChannelImpl.java:1107) ~[?:?]
	at org.h2.store.fs.FileNio.tryLock(FilePathNio.java:121) ~[?:?]
	at java.nio.channels.FileChannel.tryLock(FileChannel.java:1155) ~[?:?]
	at org.h2.mvstore.FileStore.open(FileStore.java:163) ~[?:?]
	... 56 more

I had the same issue.
What I did to solve it was remove the embedded broker thing, then remove the /var/lib/openhab2/mqttembedded.bin file and add the embedded broker thing again.

1 Like

Thanks Bram
I noticed the error was thrown by a lock on that file. I will give a try and report back. If this is the case, it probably should have an issue raised on git

@bram_dirriwachter
Thank you very much, that did the trick. Embedded mqtt broker came right back on line and mqtt rules working. I think I will attempt to find the right repo and create an issue, this is obviously a buggy

Edit to add:
There was another issue already dealing with this problem so my issue got closed. Here is a link to the other issue

old issue link for reference here:

Restarting OpenHAB has caused the embedded mqtt server to go offline again. This time I do not see the same error message about a file lock causing the problem
unstalling the broker caused this

9:15:40.238 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from OFFLINE (CONFIGURATION_ERROR): The system connection with the name embedded-mqtt-broker doesnt exist anymore. to REMOVING
19:15:40.239 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from REMOVING to REMOVED
19:15:40.243 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'mqtt:topic:a2b851fe' changed from OFFLINE (BRIDGE_OFFLINE) to UNINITIALIZED
19:15:40.252 [ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method 'Runnable.run()' on 'org.eclipse.smarthome.core.thing.internal.ThingManagerImpl$$Lambda$822/2099136298@16b8d157': org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler cannot be cast to org.openhab.binding.mqtt.handler.AbstractBrokerHandler
java.lang.ClassCastException: org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler cannot be cast to org.openhab.binding.mqtt.handler.AbstractBrokerHandler
	at org.openhab.binding.mqtt.internal.MqttBrokerHandlerFactory.lambda$0(MqttBrokerHandlerFactory.java:83) ~[?:?]
	at java.util.WeakHashMap.forEach(WeakHashMap.java:1025) ~[?:?]
	at java.util.Collections$SynchronizedMap.forEach(Collections.java:2647) ~[?:?]
	at org.openhab.binding.mqtt.internal.MqttBrokerHandlerFactory.removeHandler(MqttBrokerHandlerFactory.java:83) ~[?:?]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandlerFactory.unregisterHandler(BaseThingHandlerFactory.java:258) ~[?:?]
	at org.eclipse.smarthome.core.thing.internal.ThingManagerImpl.lambda$5(ThingManagerImpl.java:811) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [133:org.openhab.core:2.5.0.M3]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [133:org.openhab.core:2.5.0.M3]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
19:15:40.258 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'mqtt:topic:3d1078c8' changed from OFFLINE (BRIDGE_OFFLINE) to UNINITIALIZED
19:15:40.260 [ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method 'Runnable.run()' on 'org.eclipse.smarthome.core.thing.internal.ThingManagerImpl$$Lambda$822/2099136298@584ba5a8': org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler cannot be cast to org.openhab.binding.mqtt.handler.AbstractBrokerHandler
java.lang.ClassCastException: org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler cannot be cast to org.openhab.binding.mqtt.handler.AbstractBrokerHandler
	at org.openhab.binding.mqtt.internal.MqttBrokerHandlerFactory.lambda$0(MqttBrokerHandlerFactory.java:83) ~[?:?]
	at java.util.WeakHashMap.forEach(WeakHashMap.java:1025) ~[?:?]
	at java.util.Collections$SynchronizedMap.forEach(Collections.java:2647) ~[?:?]
	at org.openhab.binding.mqtt.internal.MqttBrokerHandlerFactory.removeHandler(MqttBrokerHandlerFactory.java:83) ~[?:?]
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandlerFactory.unregisterHandler(BaseThingHandlerFactory.java:258) ~[?:?]
	at org.eclipse.smarthome.core.thing.internal.ThingManagerImpl.lambda$5(ThingManagerImpl.java:811) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [133:org.openhab.core:2.5.0.M3]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [133:org.openhab.core:2.5.0.M3]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
19:15:40.263 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from REMOVED to UNINITIALIZED
19:15:40.265 [WARN ] [ng.mqtt.handler.AbstractBrokerHandler] - Trying to dispose handler mqtt:systemBroker:embedded-mqtt-broker but connection is already null. Most likely this is a bug.
19:15:40.278 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'mqtt:systemBroker:embedded-mqtt-broker' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

check out WARN at 19:15:40:265

Most likely this is a bug

So anyhow… even though this time I did not see a error about the file being locked, (I might have missed it) stopping openhab, deleting the bin file, clearing the cache and restarting OpenHAB found my old mqtt broker in the inbox
Like the warning message above says… most likely this is a bug
my issue on git doesn’t seem to be drawing much attention

Also, I have another user having a similar problem but his started on an older version and he has since upgraded to 2.5M3 in an attempt to fix it
details here
https://community.openhab.org/t/mqtt-embedded-crashed-will-not-restart/83342/9

anyhow… checked out code owners file and who is the developer for the embedded mqtt broker… none other then David Graeff
that is not sounding hopeful for getting this fixed as it seems David has lost interest in OpenHAB
see here

I don‘t get if this is a problem that occurs on every restart or only on upgrade. Can someone comment on this?

Jan, it happens on every restart

I have added code to delete the persistence if it can’t be read. I can’t reproduce the problem any longer. This requires a bugfix in moquette, too.

2 Likes

Thank you Jan for pointing out to me that the /var/lib/openhab2/mqttembedded.bin is a persistence file for the broker. I did not know that.
So… and thanks to another user, I’ve noticed in PaperUI Configuration > Services > MQTT Embedded Broker the configure button gives you a place to specify the persistence file. In the instructions it states ‘Can be empty to not store anything.’ So I’m guessing if this issue isn’t resolved a work around might be to leave this blank.

has this change been picked up in recent snapshots?
checking this PR it does not look like it made it into M4

I saw this,is this the issue?

No & no. Since Moquette development seems to have stalled, I fixed it in our fork.

1 Like

I have pushed a fix to the moquette fork that will cover the issue you linked above and also found another problem that may be the reason why the databse gets corrupted in the first place. This is also fixed in the PR to openhab2-addons.

1 Like

Thanks Jan for looking into this :+1:

Thank you Jan

While waiting for the fix, moving the persistance file to another directory might be a workaround

1 Like