microstream: store()/storeAll() causes "Storage is shut down." exception when garbage collection is involved

Environment Details

  • MicroStream Version: 05.00.02-MS-GA

Describe the bug

Since I synchronize larger amounts of data at night, I activated the MicroStream GarbageCollector, carried out the GarbageCollection and deactivated the MicroStream GarbageCollector again. After an indefinite period of time, the already known problem with store () / storeAll () and the exception “Storage is shut down” occurs. This also occurs after restarting the application and without a shutdown of the storage that I initiated or intended. No exceptions were shown to me while starting the storage. Reading the db is still partially possible.

I noticed that if this exception occurred when saving to the storage and then the application is started without the following garbage collection, then the storage can be used again without problems, i.e. store () / storeAll () is also possible again.

StorageEntityCache.Default.setGarbageCollectionEnabled (true);
STORAGE.issueFullGarbageCollection ();
StorageEntityCache.Default.setGarbageCollectionEnabled (false);

However, if the GarbageCollection is activated again the next time it is started, the store () / storeAll () problem occurs again.

Are there possibilities / methods to better document the start, the behavior or the state of the storage or the GC, or to receive specific outputs? Could you give me some code examples in this regard? I might be able to provide further / helpful information to solve this issue. It would also be possible for me to create a ThreadDump in the db after the unsuccessful write attempt, shortly after the db started.

I’ve attached the exceptions and the code for starting and shutting down.

Output Console/Log (Update of the user via store (...)):

one.microstream.persistence.exceptions.PersistenceExceptionTransfer
   at one.microstream.storage.embedded.types.EmbeddedStorageBinaryTarget$Default.write(EmbeddedStorageBinaryTarget.java:90)
   at one.microstream.storage.embedded.types.EmbeddedStorageBinaryTarget$Default.write(EmbeddedStorageBinaryTarget.java:1)
   at one.microstream.persistence.binary.types.BinaryStorer$Default.commit(BinaryStorer.java:501)
   at one.microstream.persistence.types.PersistenceManager$Default.store(PersistenceManager.java:298)
   at one.microstream.storage.types.StorageConnection.store(StorageConnection.java:367)
   at de.ui.beans.RegisterOrLogin.login(RegisterOrLogin.java:162)
   at de.ui.beans.RegisterOrLogin.txtLoginPassword_onKeyDown(RegisterOrLogin.java:298)
   at com.vaadin.flow.component.ComponentEventBus.fireEventForListener(ComponentEventBus.java:205)
   at com.vaadin.flow.component.ComponentEventBus.handleDomEvent(ComponentEventBus.java:373)
   at com.vaadin.flow.component.ComponentEventBus.lambda$addDomTrigger$dd1b7957$1(ComponentEventBus.java:264)
   at com.vaadin.flow.internal.nodefeature.ElementListenerMap.lambda$fireEvent$2(ElementListenerMap.java:441)
   at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
   at com.vaadin.flow.internal.nodefeature.ElementListenerMap.fireEvent(ElementListenerMap.java:441)
   at com.vaadin.flow.server.communication.rpc.EventRpcHandler.handleNode(EventRpcHandler.java:59)
   at com.vaadin.flow.server.communication.rpc.AbstractRpcInvocationHandler.handle(AbstractRpcInvocationHandler.java:64)
   at com.vaadin.flow.server.communication.ServerRpcHandler.handleInvocationData(ServerRpcHandler.java:409)
   at com.vaadin.flow.server.communication.ServerRpcHandler.lambda$handleInvocations$1(ServerRpcHandler.java:390)
   at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
   at com.vaadin.flow.server.communication.ServerRpcHandler.handleInvocations(ServerRpcHandler.java:390)
   at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:317)
   at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:89)
   at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40)
   at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1547)
   at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:247)
   at com.rapidclipse.framework.server.RapServlet.service(RapServlet.java:159)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:228)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
   at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
   at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
   at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
   at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
   at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
   at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
   at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1723)
   at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
   at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
   at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: one.microstream.storage.exceptions.StorageExceptionNotRunning: Storage is shut down.
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTask(StorageTaskBroker.java:212)
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTask(StorageTaskBroker.java:197)
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTaskAndNotifyAll(StorageTaskBroker.java:187)
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueStoreTask(StorageTaskBroker.java:396)
   at one.microstream.storage.types.StorageRequestAcceptor$Default.storeData(StorageRequestAcceptor.java:177)
   at one.microstream.storage.embedded.types.EmbeddedStorageBinaryTarget$Default.write(EmbeddedStorageBinaryTarget.java:86)
   ... 47 more
Output Console/Log (Update of the user via storeAll (...)):

one.microstream.persistence.exceptions.PersistenceExceptionTransfer
   at one.microstream.storage.embedded.types.EmbeddedStorageBinaryTarget$Default.write(EmbeddedStorageBinaryTarget.java:90)
   at one.microstream.storage.embedded.types.EmbeddedStorageBinaryTarget$Default.write(EmbeddedStorageBinaryTarget.java:1)
   at one.microstream.persistence.binary.types.BinaryStorer$Default.commit(BinaryStorer.java:501)
   at one.microstream.persistence.types.PersistenceManager$Default.storeAll(PersistenceManager.java:316)
   at one.microstream.storage.types.StorageConnection.storeAll(StorageConnection.java:376)
   at de.dao.UserDAO.update(UserDAO.java:131)
   at de.ui.beans.CartDialog.lambda$setContent$0(CartDialog.java:113)
   at de.ui.bits.CartProductBox.btnRemove_onClick(CartProductBox.java:267)
   at com.vaadin.flow.component.ComponentEventBus.fireEventForListener(ComponentEventBus.java:205)
   at com.vaadin.flow.component.ComponentEventBus.handleDomEvent(ComponentEventBus.java:373)
   at com.vaadin.flow.component.ComponentEventBus.lambda$addDomTrigger$dd1b7957$1(ComponentEventBus.java:264)
   at com.vaadin.flow.internal.nodefeature.ElementListenerMap.lambda$fireEvent$2(ElementListenerMap.java:441)
   at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
   at com.vaadin.flow.internal.nodefeature.ElementListenerMap.fireEvent(ElementListenerMap.java:441)
   at com.vaadin.flow.server.communication.rpc.EventRpcHandler.handleNode(EventRpcHandler.java:59)
   at com.vaadin.flow.server.communication.rpc.AbstractRpcInvocationHandler.handle(AbstractRpcInvocationHandler.java:64)
   at com.vaadin.flow.server.communication.ServerRpcHandler.handleInvocationData(ServerRpcHandler.java:409)
   at com.vaadin.flow.server.communication.ServerRpcHandler.lambda$handleInvocations$1(ServerRpcHandler.java:390)
   at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
   at com.vaadin.flow.server.communication.ServerRpcHandler.handleInvocations(ServerRpcHandler.java:390)
   at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:317)
   at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:89)
   at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40)
   at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1547)
   at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:247)
   at com.rapidclipse.framework.server.RapServlet.service(RapServlet.java:159)
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:228)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
   at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
   at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
   at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
   at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
   at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
   at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
   at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1723)
   at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
   at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
   at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: one.microstream.storage.exceptions.StorageExceptionNotRunning: Storage is shut down.
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTask(StorageTaskBroker.java:212)
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTask(StorageTaskBroker.java:197)
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueTaskAndNotifyAll(StorageTaskBroker.java:187)
   at one.microstream.storage.types.StorageTaskBroker$Default.enqueueStoreTask(StorageTaskBroker.java:396)
   at one.microstream.storage.types.StorageRequestAcceptor$Default.storeData(StorageRequestAcceptor.java:177)
   at one.microstream.storage.embedded.types.EmbeddedStorageBinaryTarget$Default.write(EmbeddedStorageBinaryTarget.java:86)
   ... 48 more
Database.java

public class Database {
    private static Logger logger = LoggerFactory.getLogger(Database.class);

	public static final Reference<Root> ROOT = X.Reference(new Root());
	public static final EmbeddedStorageManager STORAGE;
	private static final Path PATH;

	static {
		PATH = Paths.get(System.getProperty("user.home"), "MicroStream", "Shop");

		try {
			if (!PATH.toFile().exists()) {
				Files.createDirectory(Database.PATH);
				logger.info("MS-DB: No existing path to DB-files found. Path was created.");
			} else {
				logger.info("MS-DB: Already existing path to DB-files found.");		
			}
		} catch (final IOException e) {
			e.printStackTrace();
		}

        STORAGE = EmbeddedStorage.start(Database.ROOT, Database.PATH);
        StorageEntityCache.Default.setGarbageCollectionEnabled(true);
        storage.issueFullGarbageCollection();

        // As a precaution, the GC is deactivated again so that there is no risk of the shop being shut down during garbage collection, which could result in inconsistencies in the DB.
		StorageEntityCache.Default.setGarbageCollectionEnabled(false);
    }
}
MicroStreamContextDestroyer.java

@WebListener
public class MicroStreamContextDestroyer implements ServletContextListener {
	private static Logger logger = LoggerFactory.getLogger(MicroStreamContextDestroyer.class);

	@Override
	public void contextInitialized(final ServletContextEvent sce) {
	}

	@Override
	public void contextDestroyed(final ServletContextEvent sce) {
		logger.info("MicroStreamContextDestroyer: Destruction of context started.");
		
		logger.info("MS-DB STORAGE Shutdown: Check MS-DB STORAGE for shutdown.");
		if (Database.STORAGE != null) {
			if (Database.STORAGE.shutdown()) {
				logger.info("MS-DB STORAGE Shutdown: All active threads that manage the MicroStream memory have been shut down successfully.");
			} else {
				logger.error("MS-DB STORAGE Shutdown: An internal InterruptedException occurred during the shutdown of all active threads that manage the MicroStream memory.");
			}
		} else {
			logger.info("MS-DB Shutdown: No started MS-DB found to shut down.");
		}
		
		// Stop the LazyReference Manager to prevent memory leaks.
		LazyReferenceManager lazyReferenceManager = LazyReferenceManager.get();
		if (lazyReferenceManager != null) {
			lazyReferenceManager.stop();
			logger.info("MS-DB LazyReferenceManager Shutdown: LazyReferenceManager triggered to stop.");
		} else {
			logger.error("MS-DB LazyReferenceManager Shutdown: No LazyReferenceManager found to stop.");
		}
		logger.info("MicroStreamContextDestroyer: Destruction of context finished.");
	}
}

Additional context

  • This issue has existed since version 04.01.00-MS-GA.
  • No lazy references are used.

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 18 (10 by maintainers)

Commits related to this issue

Most upvoted comments

Hello, We just released the new Version 06.01.00-MS-GA that contains several bug fixes including fixes for this issue.

It’s nice to hear that the cause has been found and resolved! Is it planned or possible to release a bugfix release soon instead of waiting for the major release? That would be really great and I would be very grateful to you!

We plan to do a minor release containing that fix. Please apologize that I can’t tell when this will be available at the moment.

Is this a bug that is a high priority for you and you are currently working on a solution?

Yes, we’re working on that currently. But currently I can’t make any estimations how long this will take.

(Maybe the StorageEventLogger.Default implementation may be sufficient too)

I think that was a typo and you must mean StorageEventLogger.Debug().

I implemented it and got the following output, which you have probably already seen in connection with the “StorageIsShutdown” exception:

12.10 14:17:32 [http-nio-8081-exec-1] INFO  [de.ui.views.Debug]  Starting manually MS-DB-Housekeeping-FullGarbageCollection...
12.10 14:17:32 [http-nio-8081-exec-1] INFO  [de.ui.views.Debug]  GC: StorageEntityCache.Default.setGarbageCollectionEnabled(true)
.sweep(StorageEntityCache.java:1016)                            14:17:33.520> StorageChannel#0 completed sweeping.
.completeSweep(StorageEntityMarkMonitor.java:536)               14:17:33.521> Completed GC Hot Phase #1 @ 1634041053521
.sweep(StorageEntityCache.java:1016)                            14:17:36.360> StorageChannel#0 completed sweeping.
.completeSweep(StorageEntityMarkMonitor.java:536)               14:17:36.361> Storage-GC completed #1 @ 1634041056360
12.10 14:17:36 [http-nio-8081-exec-1] INFO  [de.ui.views.Debug]  GC: STORAGE.issueFullGarbageCollection()
12.10 14:17:36 [http-nio-8081-exec-1] INFO  [de.ui.views.Debug]  GC: StorageEntityCache.Default.setGarbageCollectionEnabled(false)
.run(StorageChannel.java:495)                                   14:17:37.380> StorageChannel#0 encountered exception java.lang.NullPointerException: Cannot read field "file" because "<parameter1>" is null
.run(StorageChannel.java:495)                                   14:17:37.380> StorageChannel#0 processing disabled.
.run(StorageChannel.java:495)                                   14:17:37.380> StorageChannel#0 stopped working.

The NullPointer “Cannot read field file because <parameter1> is null” indicates that this is the same bug we can reproduce and we’re currently analyzing.