ISPN000136: Error executing command SizeCommand, writing keys[]

[atuldas]

I have a infinispan cache connected through Oracle DB.
I have a process that does a transaction on USER cache to check it's size.
This operation throws an exception ->
InvocationContextInterceptor ISPN000136: Error executing command SizeCommand, writing keys []
org.infinispan.persistence.spi.StoreUnavailableException: Store org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore@6492d69d is unavailable
at org.infinispan.persistence.manager.PersistenceManagerImpl.pollStoreAvailability(PersistenceManagerImpl.java:198) ~[ibis_tools.jar:8.0.22]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
at java.lang.Thread.run(Thread.java:829) ~[?:?]

What are the possible causes for this error to come up?

[tristantarrant]

It means that the connection pool has been disconnected from the DB. You should have seen ISPN000678 in your logs at some point. The persistence manager polls the store periodically to verify availability. In the case of a JDBC store, this means the ability to acquire a connection to the database.

[atuldas]

JDBC connection is happening through managed data source. These details are stored in configuration files of type .xml. Then this database has a table called USER, which in the backend implements the Cache Interface like 'private final Cache userCache;'.
Hope this answers your question.

[ryanemerson]

@atuldas Can you enable trace logs for org.infinispan.persistence.jdbc, reproduce and upload your logs?

[atuldas]

I will not be able to share the logs as I am unable to reproduce this error. The issue is faced by the customer, and I don't have rights to share them.

[atuldas]

@ryanemerson and @tristantarrant However, I have one more observation. This error trace is continuously seen in my logs. It says,
Suppressed: org.infinispan.util.logging.TraceException. Do you have any inputs on the causes or reasons for this error to come endlessly?
The image is attached below for reference. (Not sure if it will upload).
One information is that the backup of DB happens everyday during this period when error is seen. Is it possible that the backup operation causes the DB or cache to be unavailable at that time?

[atuldas]

The error stack is like -
InvocationContextInterceptor ISPN000136: Error executing command SizeCommand, writing keys []
org.infinispan.persistence.spi.StoreUnavailableException: Store org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore@7498f343 is unavailable
at org.infinispan.persistence.manager.PersistenceManagerImpl.pollStoreAvailability(PersistenceManagerImpl.java:198) ~[ibis_tools.jar:8.0.22]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
at java.lang.Thread.run(Thread.java:829) ~[?:?]
Suppressed: org.infinispan.util.logging.TraceException
at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41) ~[ibis_tools.jar:8.0.22]
at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:491) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.DecoratedCache.size(DecoratedCache.java:518) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.AbstractDelegatingCache.size(AbstractDelegatingCache.java:373) ~[ibis_tools.jar:8.0.22]
at com.inubit.ibis.server.cache.ispn.ISPNCache.size(ISPNCache.java:631) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.cache.AbstractCache.size(AbstractCache.java:236) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.CacheFacadeUtil.getCacheKeyNames(CacheFacadeUtil.java:45) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.UserDataCacheFacade.getUserNames(UserDataCacheFacade.java:152) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUserNames(IBISUserEngine.java:187) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.checkUserIgnoreCase(IBISUserEngine.java:1005) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUser(IBISUserEngine.java:936) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.isUser(IBISUserEngine.java:1211) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getDirectoryForUserOrUserGroup(IBISUserEngine.java:1166) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISCore.processWorkflow(IBISCore.java:261) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.processWorkflowThread(IBISSchedulerThread.java:323) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.run(IBISSchedulerThread.java:195) ~[ibis.jar:8.0.22]
at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41) ~[ibis_tools.jar:8.0.22]
at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:491) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.DecoratedCache.size(DecoratedCache.java:518) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.AbstractDelegatingCache.size(AbstractDelegatingCache.java:373) ~[ibis_tools.jar:8.0.22]
at com.inubit.ibis.server.cache.ispn.ISPNCache.size(ISPNCache.java:631) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.cache.AbstractCache.size(AbstractCache.java:236) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.CacheFacadeUtil.getCacheKeyNames(CacheFacadeUtil.java:45) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.UserDataCacheFacade.getUserNames(UserDataCacheFacade.java:152) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUserNames(IBISUserEngine.java:187) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.checkUserIgnoreCase(IBISUserEngine.java:1005) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUser(IBISUserEngine.java:936) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.isUser(IBISUserEngine.java:1211) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getDirectoryForUserOrUserGroup(IBISUserEngine.java:1166) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISCore.processWorkflow(IBISCore.java:261) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.processWorkflowThread(IBISSchedulerThread.java:323) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.run(IBISSchedulerThread.java:195) ~[ibis.jar:8.0.22]
Suppressed: org.infinispan.util.logging.TraceException
at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41) ~[ibis_tools.jar:8.0.22]
at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:491) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.DecoratedCache.size(DecoratedCache.java:518) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.AbstractDelegatingCache.size(AbstractDelegatingCache.java:373) ~[ibis_tools.jar:8.0.22]
at com.inubit.ibis.server.cache.ispn.ISPNCache.size(ISPNCache.java:631) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.cache.AbstractCache.size(AbstractCache.java:236) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.CacheFacadeUtil.getCacheKeyNames(CacheFacadeUtil.java:45) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.UserDataCacheFacade.getUserNames(UserDataCacheFacade.java:152) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUserNames(IBISUserEngine.java:187) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.checkUserIgnoreCase(IBISUserEngine.java:1005) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUser(IBISUserEngine.java:936) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.isUser(IBISUserEngine.java:1211) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getDirectoryForUserOrUserGroup(IBISUserEngine.java:1166) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISCore.processWorkflow(IBISCore.java:261) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.processWorkflowThread(IBISSchedulerThread.java:323) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.run(IBISSchedulerThread.java:195) ~[ibis.jar:8.0.22]
Suppressed: org.infinispan.util.logging.TraceException
at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41) ~[ibis_tools.jar:8.0.22]
at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:491) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.DecoratedCache.size(DecoratedCache.java:518) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.AbstractDelegatingCache.size(AbstractDelegatingCache.java:373) ~[ibis_tools.jar:8.0.22]
at com.inubit.ibis.server.cache.ispn.ISPNCache.size(ISPNCache.java:631) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.cache.AbstractCache.size(AbstractCache.java:236) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.CacheFacadeUtil.getCacheKeyNames(CacheFacadeUtil.java:45) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.UserDataCacheFacade.getUserNames(UserDataCacheFacade.java:152) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUserNames(IBISUserEngine.java:187) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.checkUserIgnoreCase(IBISUserEngine.java:1005) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUser(IBISUserEngine.java:936) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.isUser(IBISUserEngine.java:1211) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getDirectoryForUserOrUserGroup(IBISUserEngine.java:1166) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISCore.processWorkflow(IBISCore.java:261) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.processWorkflowThread(IBISSchedulerThread.java:323) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.run(IBISSchedulerThread.java:195) ~[ibis.jar:8.0.22]
Suppressed: org.infinispan.util.logging.TraceException
at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41) ~[ibis_tools.jar:8.0.22]
at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.CacheImpl.size(CacheImpl.java:491) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.DecoratedCache.size(DecoratedCache.java:518) ~[ibis_tools.jar:8.0.22]
at org.infinispan.cache.impl.AbstractDelegatingCache.size(AbstractDelegatingCache.java:373) ~[ibis_tools.jar:8.0.22]
at com.inubit.ibis.server.cache.ispn.ISPNCache.size(ISPNCache.java:631) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.cache.AbstractCache.size(AbstractCache.java:236) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.CacheFacadeUtil.getCacheKeyNames(CacheFacadeUtil.java:45) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.datafacade.cache.UserDataCacheFacade.getUserNames(UserDataCacheFacade.java:152) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUserNames(IBISUserEngine.java:187) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.checkUserIgnoreCase(IBISUserEngine.java:1005) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getUser(IBISUserEngine.java:936) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.isUser(IBISUserEngine.java:1211) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISUserEngine.getDirectoryForUserOrUserGroup(IBISUserEngine.java:1166) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISCore.processWorkflow(IBISCore.java:261) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.processWorkflowThread(IBISSchedulerThread.java:323) ~[ibis.jar:8.0.22]
at com.inubit.ibis.server.IBISSchedulerThread.run(IBISSchedulerThread.java:195) ~[ibis.jar:8.0.22]

[ryanemerson]

One information is that the backup of DB happens everyday during this period when error is seen. Is it possible that the backup operation causes the DB or cache to be unavailable at that time?

Possibly. The error will be thrown whenever the Infinispan PersistenceManager polls the availability of the JDBC store and a connection to the underlying DB cannot be established. I suggest you check the semantics of the Oracle DB backup operation(s) you're using and see if this has any affect on DB availability.