[
https://issues.jboss.org/browse/ISPN-9798?page=com.atlassian.jira.plugin....
]
xiaodong xie updated ISPN-9798:
-------------------------------
Description:
We are using Infinispan-9.3.1.Final in Wildfly-14.0.1.Final.
We have a local cache backed with a file store, the configuration is like this:
{noformat}
<local-cache name="our-cache">
<locking acquire-timeout="500"/>
<object-memory size="80000"/>
<file-store passivation="false" preload="true"
purge="false"/>
</local-cache>
{noformat}
And in the code, we put into the cache with code like this:
ourCache.put(key, value, 5, TimeUnit.MINUTES);
(We were doing this because in older version of Wildfly, the expiration timeout in the
configuration file was not respected. The timeout in prod would be much higher than 5
minutes of course, just for demonstration purpose here).
When Wildfly-14.0.1.Final boots up, if it has been down 5 minutes, all entries would be
expired.
And usually the number of requests that use the cache is really high, which ends up the
following situation:
"expiration-thread--p9-t1" #203 daemon prio=1 os_prio=0 cpu=121.75ms
elapsed=67.73s allocated=2513K defined_classes=6 tid=0x0000000009469800 nid=0x7479 waiting
for monitor entry [0x00007f92c43ce000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1924)
- waiting to lock <0x0000000719600070> (a
java.util.concurrent.ConcurrentHashMap$Node)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.remap(BoundedLocalCache.java:2194)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.compute(BoundedLocalCache.java:2146)
at com.github.benmanes.caffeine.cache.LocalCache.compute(LocalCache.java:100)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:222)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:241)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.handleInStoreExpiration(ExpirationManagerImpl.java:163)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.handleInStoreExpiration(ExpirationManagerImpl.java:154)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$AdvancedPurgeListener.entryPurged(PersistenceManagerImpl.java:414)
at org.infinispan.persistence.file.SingleFileStore.purge(SingleFileStore.java:679)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.lambda$purgeExpired$6(PersistenceManagerImpl.java:442)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$$Lambda$1356/0x0000000801fd6040.accept(Unknown
Source)
at java.util.ArrayList.forEach(java.base@11.0.1/ArrayList.java:1540)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.purgeExpired(PersistenceManagerImpl.java:445)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.processExpiration(ExpirationManagerImpl.java:108)
at
org.infinispan.expiration.impl.ExpirationManagerImpl$ScheduledTask.run(ExpirationManagerImpl.java:241)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.1/Executors.java:515)
at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.1/FutureTask.java:305)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.1/ScheduledThreadPoolExecutor.java:305)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory$$Lambda$860/0x000000080130e440.run(Unknown
Source)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- <0x000000068be00860> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"persistence-thread--p11-t4" #215 daemon prio=5 os_prio=0 cpu=1.38ms
elapsed=63.74s allocated=672B defined_classes=0 tid=0x0000000005552800 nid=0x748c waiting
on condition [0x00007f92c4eda000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.1/AbstractQueuedSynchronizer.java:917)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.1/AbstractQueuedSynchronizer.java:1240)
at
java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:959)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.pollStoreAvailability(PersistenceManagerImpl.java:170)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$$Lambda$923/0x0000000801469040.run(Unknown
Source)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.1/Executors.java:515)
at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.1/FutureTask.java:305)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.1/ScheduledThreadPoolExecutor.java:305)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory$$Lambda$860/0x000000080130e440.run(Unknown
Source)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- <0x00000006912003f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"default task-6" #337 prio=5 os_prio=0 cpu=1361.85ms elapsed=27.80s
allocated=40M defined_classes=131 tid=0x0000000009ad3800 nid=0x758b waiting on condition
[0x00007f92b0766000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1009)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1324)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:738)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:544)
at
org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:219)
at
org.infinispan.persistence.PersistenceUtil.lambda$loadAndComputeInDataContainer$1(PersistenceUtil.java:179)
at
org.infinispan.persistence.PersistenceUtil$$Lambda$1207/0x0000000801e89040.compute(Unknown
Source)
at
org.infinispan.container.impl.AbstractInternalDataContainer.lambda$compute$3(AbstractInternalDataContainer.java:223)
at
org.infinispan.container.impl.AbstractInternalDataContainer$$Lambda$1208/0x0000000801e89c40.apply(Unknown
Source)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$remap$16(BoundedLocalCache.java:2199)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$1209/0x0000000801e8a440.apply(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1947)
- locked <0x0000000719600070> (a java.util.concurrent.ConcurrentHashMap$Node)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.remap(BoundedLocalCache.java:2194)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.compute(BoundedLocalCache.java:2146)
at com.github.benmanes.caffeine.cache.LocalCache.compute(LocalCache.java:100)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:222)
at
org.infinispan.persistence.PersistenceUtil.loadAndComputeInDataContainer(PersistenceUtil.java:201)
at
org.infinispan.persistence.PersistenceUtil.loadAndStoreInDataContainer(PersistenceUtil.java:135)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.loadInContext(CacheLoaderInterceptor.java:310)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:305)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitDataCommand(CacheLoaderInterceptor.java:189)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:118)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(BaseAsyncInterceptor.java:98)
at
org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:672)
at
org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:302)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:150)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.lambda$nonTxLockAndInvokeNext$1(AbstractLockingInterceptor.java:299)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor$$Lambda$1214/0x0000000801eac840.apply(Unknown
Source)
at
org.infinispan.interceptors.SyncInvocationStage.addCallback(SyncInvocationStage.java:42)
at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.nonTxLockAndInvokeNext(AbstractLockingInterceptor.java:294)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:126)
at
org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:82)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
at
org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248)
at
org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1708)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1370)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1834)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1355)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:232)
at
org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:116)
at org.infinispan.cache.impl.EncoderCache.put(EncoderCache.java:195)
at
org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:116)
at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at
org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:90)
at
org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101)
at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at
org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:237)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:362)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:72)
at
org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.as.ejb3.component.singleton.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:106)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at
org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at
org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at
org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
at
org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:410)
at
org.jboss.weld.module.ejb.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:134)
at
org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56)
at
org.jboss.weld.module.ejb.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:68)
at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:106)
at jdk.internal.reflect.GeneratedMethodAccessor221.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140)
at
org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399)
at
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363)
at
org.jboss.resteasy.core.ResourceMethodInvoker$$Lambda$1165/0x0000000801da4040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
- locked <0x0000000710fa2020> (a
org.jboss.resteasy.core.interception.PostMatchContainerRequestContext)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:310)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:443)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:233)
at
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$1160/0x0000000801da6c40.run(Unknown
Source)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:139)
at
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$1161/0x0000000801da6040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
- locked <0x0000000710fa2078> (a
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext)
at
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:142)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:219)
at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at
io.opentracing.contrib.jaxrs2.server.SpanFinishingFilter.doFilter(SpanFinishingFilter.java:55)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
at
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
at
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at
org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
at
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at
io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at
io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction$$Lambda$1063/0x000000080183d840.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
at
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- None
And all other task threads from Wildfly were at some state like this:
"default task-22" #353 prio=5 os_prio=0 cpu=1166.75ms elapsed=27.62s
allocated=31M defined_classes=18 tid=0x00000000033d5000 nid=0x75a1 waiting on condition
[0x00007f92af453000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1009)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1324)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:738)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:544)
at
org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:219)
at
org.infinispan.persistence.PersistenceUtil.lambda$loadAndComputeInDataContainer$1(PersistenceUtil.java:179)
at
org.infinispan.persistence.PersistenceUtil$$Lambda$1207/0x0000000801e89040.compute(Unknown
Source)
at
org.infinispan.container.impl.AbstractInternalDataContainer.lambda$compute$3(AbstractInternalDataContainer.java:223)
at
org.infinispan.container.impl.AbstractInternalDataContainer$$Lambda$1208/0x0000000801e89c40.apply(Unknown
Source)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$remap$16(BoundedLocalCache.java:2199)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$1209/0x0000000801e8a440.apply(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1908)
- locked <0x0000000710d8d910> (a
java.util.concurrent.ConcurrentHashMap$ReservationNode)
Here is my understanding:
1. "default task-6" locked "0x0000000719600070", then waiting for the
read lock in "PersistenceManagerImpl".
2. "expiration-thread--p9-t1" grabbed read lock (based on the source code, it
must have grabbed the read lock in order to reach locking "0x0000000719600070"),
then waiting to lock "0x0000000719600070".
3. "persistence-thread--p11-t4" would like to grab the write lock in order to
continue.
4. "PersistenceManagerImpl" uses "NonfairSync", based on this
implementation in "ReentrantReadWriteLock" in openJDK-11.0.1
{code:java}
/**
* Nonfair version of Sync
*/
static final class NonfairSync extends Sync {
private static final long serialVersionUID = -8159625535654395037L;
final boolean writerShouldBlock() {
return false; // writers can always barge
}
final boolean readerShouldBlock() {
/* As a heuristic to avoid indefinite writer starvation,
* block if the thread that momentarily appears to be head
* of queue, if one exists, is a waiting writer. This is
* only a probabilistic effect since a new reader will not
* block if there is a waiting writer behind other enabled
* readers that have not yet drained from the queue.
*/
return apparentlyFirstQueuedIsExclusive();
}
}
{code}
It seems to me that the writer ("persistence-thread--p11-t4") has reached
the head of queue, so the reader "default task-6" cannot continue (in order not
to starve the writer). So the lock ("0x0000000719600070") locked by this this
reader "default task-6" cannot be released, which caused the reader thread
"expiration-thread--p9-t1" cannot continue. So here a deadlock was formed.
I here propose a way to avoid this deadlock by only using
"storesMutex.writeLock().tryLock()" in "pollStoreAvailability".
Also, Wildfly should provide a way to set "availabilityInterval".
was:
{noformat}
*no* further _formatting_ is done here
{noformat}
We are using Infinispan-9.3.1.Final in Wildfly-14.0.1.Final.
We have a local cache backed with a file store, the configuration is like this:
<local-cache name="our-cache">
<locking acquire-timeout="500"/>
<object-memory size="80000"/>
<file-store passivation="false" preload="true"
purge="false"/>
</local-cache>
And in the code, we put into the cache with code like this:
ourCache.put(key, value, 5, TimeUnit.MINUTES);
(We were doing this because in older version of Wildfly, the expiration timeout in the
configuration file was not respected. The timeout in prod would be much higher than 5
minutes of course, just for demonstration purpose here).
When Wildfly-14.0.1.Final boots up, if it has been down 5 minutes, all entries would be
expired.
And usually the number of requests that use the cache is really high, which ends up the
following situation:
"expiration-thread--p9-t1" #203 daemon prio=1 os_prio=0 cpu=121.75ms
elapsed=67.73s allocated=2513K defined_classes=6 tid=0x0000000009469800 nid=0x7479 waiting
for monitor entry [0x00007f92c43ce000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1924)
- waiting to lock <0x0000000719600070> (a
java.util.concurrent.ConcurrentHashMap$Node)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.remap(BoundedLocalCache.java:2194)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.compute(BoundedLocalCache.java:2146)
at com.github.benmanes.caffeine.cache.LocalCache.compute(LocalCache.java:100)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:222)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:241)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.handleInStoreExpiration(ExpirationManagerImpl.java:163)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.handleInStoreExpiration(ExpirationManagerImpl.java:154)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$AdvancedPurgeListener.entryPurged(PersistenceManagerImpl.java:414)
at org.infinispan.persistence.file.SingleFileStore.purge(SingleFileStore.java:679)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.lambda$purgeExpired$6(PersistenceManagerImpl.java:442)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$$Lambda$1356/0x0000000801fd6040.accept(Unknown
Source)
at java.util.ArrayList.forEach(java.base@11.0.1/ArrayList.java:1540)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.purgeExpired(PersistenceManagerImpl.java:445)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.processExpiration(ExpirationManagerImpl.java:108)
at
org.infinispan.expiration.impl.ExpirationManagerImpl$ScheduledTask.run(ExpirationManagerImpl.java:241)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.1/Executors.java:515)
at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.1/FutureTask.java:305)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.1/ScheduledThreadPoolExecutor.java:305)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory$$Lambda$860/0x000000080130e440.run(Unknown
Source)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- <0x000000068be00860> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"persistence-thread--p11-t4" #215 daemon prio=5 os_prio=0 cpu=1.38ms
elapsed=63.74s allocated=672B defined_classes=0 tid=0x0000000005552800 nid=0x748c waiting
on condition [0x00007f92c4eda000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.1/AbstractQueuedSynchronizer.java:917)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.1/AbstractQueuedSynchronizer.java:1240)
at
java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:959)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.pollStoreAvailability(PersistenceManagerImpl.java:170)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$$Lambda$923/0x0000000801469040.run(Unknown
Source)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.1/Executors.java:515)
at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.1/FutureTask.java:305)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.1/ScheduledThreadPoolExecutor.java:305)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory$$Lambda$860/0x000000080130e440.run(Unknown
Source)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- <0x00000006912003f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"default task-6" #337 prio=5 os_prio=0 cpu=1361.85ms elapsed=27.80s
allocated=40M defined_classes=131 tid=0x0000000009ad3800 nid=0x758b waiting on condition
[0x00007f92b0766000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1009)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1324)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:738)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:544)
at
org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:219)
at
org.infinispan.persistence.PersistenceUtil.lambda$loadAndComputeInDataContainer$1(PersistenceUtil.java:179)
at
org.infinispan.persistence.PersistenceUtil$$Lambda$1207/0x0000000801e89040.compute(Unknown
Source)
at
org.infinispan.container.impl.AbstractInternalDataContainer.lambda$compute$3(AbstractInternalDataContainer.java:223)
at
org.infinispan.container.impl.AbstractInternalDataContainer$$Lambda$1208/0x0000000801e89c40.apply(Unknown
Source)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$remap$16(BoundedLocalCache.java:2199)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$1209/0x0000000801e8a440.apply(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1947)
- locked <0x0000000719600070> (a java.util.concurrent.ConcurrentHashMap$Node)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.remap(BoundedLocalCache.java:2194)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.compute(BoundedLocalCache.java:2146)
at com.github.benmanes.caffeine.cache.LocalCache.compute(LocalCache.java:100)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:222)
at
org.infinispan.persistence.PersistenceUtil.loadAndComputeInDataContainer(PersistenceUtil.java:201)
at
org.infinispan.persistence.PersistenceUtil.loadAndStoreInDataContainer(PersistenceUtil.java:135)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.loadInContext(CacheLoaderInterceptor.java:310)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:305)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitDataCommand(CacheLoaderInterceptor.java:189)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:118)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(BaseAsyncInterceptor.java:98)
at
org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:672)
at
org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:302)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:150)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.lambda$nonTxLockAndInvokeNext$1(AbstractLockingInterceptor.java:299)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor$$Lambda$1214/0x0000000801eac840.apply(Unknown
Source)
at
org.infinispan.interceptors.SyncInvocationStage.addCallback(SyncInvocationStage.java:42)
at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.nonTxLockAndInvokeNext(AbstractLockingInterceptor.java:294)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:126)
at
org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:82)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
at
org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248)
at
org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1708)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1370)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1834)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1355)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:232)
at
org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:116)
at org.infinispan.cache.impl.EncoderCache.put(EncoderCache.java:195)
at
org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:116)
at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at
org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:90)
at
org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101)
at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at
org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:237)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:362)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:72)
at
org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.as.ejb3.component.singleton.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:106)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at
org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at
org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at
org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
at
org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:410)
at
org.jboss.weld.module.ejb.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:134)
at
org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56)
at
org.jboss.weld.module.ejb.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:68)
at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:106)
at jdk.internal.reflect.GeneratedMethodAccessor221.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140)
at
org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399)
at
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363)
at
org.jboss.resteasy.core.ResourceMethodInvoker$$Lambda$1165/0x0000000801da4040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
- locked <0x0000000710fa2020> (a
org.jboss.resteasy.core.interception.PostMatchContainerRequestContext)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:310)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:443)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:233)
at
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$1160/0x0000000801da6c40.run(Unknown
Source)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:139)
at
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$1161/0x0000000801da6040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
- locked <0x0000000710fa2078> (a
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext)
at
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:142)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:219)
at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at
io.opentracing.contrib.jaxrs2.server.SpanFinishingFilter.doFilter(SpanFinishingFilter.java:55)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
at
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
at
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at
org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
at
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at
io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at
io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction$$Lambda$1063/0x000000080183d840.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
at
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- None
And all other task threads from Wildfly were at some state like this:
"default task-22" #353 prio=5 os_prio=0 cpu=1166.75ms elapsed=27.62s
allocated=31M defined_classes=18 tid=0x00000000033d5000 nid=0x75a1 waiting on condition
[0x00007f92af453000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1009)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1324)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:738)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:544)
at
org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:219)
at
org.infinispan.persistence.PersistenceUtil.lambda$loadAndComputeInDataContainer$1(PersistenceUtil.java:179)
at
org.infinispan.persistence.PersistenceUtil$$Lambda$1207/0x0000000801e89040.compute(Unknown
Source)
at
org.infinispan.container.impl.AbstractInternalDataContainer.lambda$compute$3(AbstractInternalDataContainer.java:223)
at
org.infinispan.container.impl.AbstractInternalDataContainer$$Lambda$1208/0x0000000801e89c40.apply(Unknown
Source)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$remap$16(BoundedLocalCache.java:2199)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$1209/0x0000000801e8a440.apply(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1908)
- locked <0x0000000710d8d910> (a
java.util.concurrent.ConcurrentHashMap$ReservationNode)
Here is my understanding:
1. "default task-6" locked "0x0000000719600070", then waiting for the
read lock in "PersistenceManagerImpl".
2. "expiration-thread--p9-t1" grabbed read lock (based on the source code, it
must have grabbed the read lock in order to reach locking "0x0000000719600070"),
then waiting to lock "0x0000000719600070".
3. "persistence-thread--p11-t4" would like to grab the write lock in order to
continue.
4. "PersistenceManagerImpl" uses "NonfairSync", based on this
implementation in "ReentrantReadWriteLock" in openJDK-11.0.1
{code:java}
/**
* Nonfair version of Sync
*/
static final class NonfairSync extends Sync {
private static final long serialVersionUID = -8159625535654395037L;
final boolean writerShouldBlock() {
return false; // writers can always barge
}
final boolean readerShouldBlock() {
/* As a heuristic to avoid indefinite writer starvation,
* block if the thread that momentarily appears to be head
* of queue, if one exists, is a waiting writer. This is
* only a probabilistic effect since a new reader will not
* block if there is a waiting writer behind other enabled
* readers that have not yet drained from the queue.
*/
return apparentlyFirstQueuedIsExclusive();
}
}
{code}
It seems to me that the writer ("persistence-thread--p11-t4") has reached
the head of queue, so the reader "default task-6" cannot continue (in order not
to starve the writer). So the lock ("0x0000000719600070") locked by this this
reader "default task-6" cannot be released, which caused the reader thread
"expiration-thread--p9-t1" cannot continue. So here a deadlock was formed.
I here propose a way to avoid this deadlock by only using
"storesMutex.writeLock().tryLock()" in "pollStoreAvailability".
Also, Wildfly should provide a way to set "availabilityInterval".
Deadlock in org.infinispan.persistence.manager.PersistenceManagerImpl
when using infinispan in Wildfly-14.0.1.Final
-------------------------------------------------------------------------------------------------------------------
Key: ISPN-9798
URL:
https://issues.jboss.org/browse/ISPN-9798
Project: Infinispan
Issue Type: Bug
Components: Core
Affects Versions: 9.3.1.Final
Environment: Wildfly-14.0.1.Final running with OpenJDK-11.0.1, on Ubuntu-14.04
Reporter: xiaodong xie
Priority: Critical
We are using Infinispan-9.3.1.Final in Wildfly-14.0.1.Final.
We have a local cache backed with a file store, the configuration is like this:
{noformat}
<local-cache name="our-cache">
<locking acquire-timeout="500"/>
<object-memory size="80000"/>
<file-store passivation="false" preload="true"
purge="false"/>
</local-cache>
{noformat}
And in the code, we put into the cache with code like this:
ourCache.put(key, value, 5, TimeUnit.MINUTES);
(We were doing this because in older version of Wildfly, the expiration timeout in the
configuration file was not respected. The timeout in prod would be much higher than 5
minutes of course, just for demonstration purpose here).
When Wildfly-14.0.1.Final boots up, if it has been down 5 minutes, all entries would be
expired.
And usually the number of requests that use the cache is really high, which ends up the
following situation:
"expiration-thread--p9-t1" #203 daemon prio=1 os_prio=0 cpu=121.75ms
elapsed=67.73s allocated=2513K defined_classes=6 tid=0x0000000009469800 nid=0x7479 waiting
for monitor entry [0x00007f92c43ce000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1924)
- waiting to lock <0x0000000719600070> (a
java.util.concurrent.ConcurrentHashMap$Node)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.remap(BoundedLocalCache.java:2194)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.compute(BoundedLocalCache.java:2146)
at com.github.benmanes.caffeine.cache.LocalCache.compute(LocalCache.java:100)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:222)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:241)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.handleInStoreExpiration(ExpirationManagerImpl.java:163)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.handleInStoreExpiration(ExpirationManagerImpl.java:154)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$AdvancedPurgeListener.entryPurged(PersistenceManagerImpl.java:414)
at org.infinispan.persistence.file.SingleFileStore.purge(SingleFileStore.java:679)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.lambda$purgeExpired$6(PersistenceManagerImpl.java:442)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$$Lambda$1356/0x0000000801fd6040.accept(Unknown
Source)
at java.util.ArrayList.forEach(java.base@11.0.1/ArrayList.java:1540)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.purgeExpired(PersistenceManagerImpl.java:445)
at
org.infinispan.expiration.impl.ExpirationManagerImpl.processExpiration(ExpirationManagerImpl.java:108)
at
org.infinispan.expiration.impl.ExpirationManagerImpl$ScheduledTask.run(ExpirationManagerImpl.java:241)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.1/Executors.java:515)
at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.1/FutureTask.java:305)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.1/ScheduledThreadPoolExecutor.java:305)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory$$Lambda$860/0x000000080130e440.run(Unknown
Source)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- <0x000000068be00860> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"persistence-thread--p11-t4" #215 daemon prio=5 os_prio=0 cpu=1.38ms
elapsed=63.74s allocated=672B defined_classes=0 tid=0x0000000005552800 nid=0x748c waiting
on condition [0x00007f92c4eda000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.1/AbstractQueuedSynchronizer.java:917)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.1/AbstractQueuedSynchronizer.java:1240)
at
java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:959)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.pollStoreAvailability(PersistenceManagerImpl.java:170)
at
org.infinispan.persistence.manager.PersistenceManagerImpl$$Lambda$923/0x0000000801469040.run(Unknown
Source)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.1/Executors.java:515)
at java.util.concurrent.FutureTask.runAndReset(java.base@11.0.1/FutureTask.java:305)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(java.base@11.0.1/ScheduledThreadPoolExecutor.java:305)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
at
org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory$$Lambda$860/0x000000080130e440.run(Unknown
Source)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- <0x00000006912003f0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"default task-6" #337 prio=5 os_prio=0 cpu=1361.85ms elapsed=27.80s
allocated=40M defined_classes=131 tid=0x0000000009ad3800 nid=0x758b waiting on condition
[0x00007f92b0766000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1009)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1324)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:738)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:544)
at
org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:219)
at
org.infinispan.persistence.PersistenceUtil.lambda$loadAndComputeInDataContainer$1(PersistenceUtil.java:179)
at
org.infinispan.persistence.PersistenceUtil$$Lambda$1207/0x0000000801e89040.compute(Unknown
Source)
at
org.infinispan.container.impl.AbstractInternalDataContainer.lambda$compute$3(AbstractInternalDataContainer.java:223)
at
org.infinispan.container.impl.AbstractInternalDataContainer$$Lambda$1208/0x0000000801e89c40.apply(Unknown
Source)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$remap$16(BoundedLocalCache.java:2199)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$1209/0x0000000801e8a440.apply(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1947)
- locked <0x0000000719600070> (a java.util.concurrent.ConcurrentHashMap$Node)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.remap(BoundedLocalCache.java:2194)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.compute(BoundedLocalCache.java:2146)
at com.github.benmanes.caffeine.cache.LocalCache.compute(LocalCache.java:100)
at
org.infinispan.container.impl.AbstractInternalDataContainer.compute(AbstractInternalDataContainer.java:222)
at
org.infinispan.persistence.PersistenceUtil.loadAndComputeInDataContainer(PersistenceUtil.java:201)
at
org.infinispan.persistence.PersistenceUtil.loadAndStoreInDataContainer(PersistenceUtil.java:135)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.loadInContext(CacheLoaderInterceptor.java:310)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:305)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitDataCommand(CacheLoaderInterceptor.java:189)
at
org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:118)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(BaseAsyncInterceptor.java:98)
at
org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:672)
at
org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:302)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:150)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.lambda$nonTxLockAndInvokeNext$1(AbstractLockingInterceptor.java:299)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor$$Lambda$1214/0x0000000801eac840.apply(Unknown
Source)
at
org.infinispan.interceptors.SyncInvocationStage.addCallback(SyncInvocationStage.java:42)
at org.infinispan.interceptors.InvocationStage.andHandle(InvocationStage.java:65)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.nonTxLockAndInvokeNext(AbstractLockingInterceptor.java:294)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:126)
at
org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:40)
at
org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:82)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
at
org.infinispan.interceptors.DDAsyncInterceptor.visitPutKeyValueCommand(DDAsyncInterceptor.java:60)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:68)
at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
at
org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248)
at
org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1708)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1370)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1834)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1355)
at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:232)
at
org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:116)
at org.infinispan.cache.impl.EncoderCache.put(EncoderCache.java:195)
at
org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:116)
at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at
org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:90)
at
org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:101)
at
org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at
org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:237)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:362)
at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:72)
at
org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at
org.jboss.as.ejb3.component.singleton.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:106)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at
org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at
org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at
org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at
org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
at
org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at org.jboss.weld.util.reflection.Reflections.invokeAndUnwrap(Reflections.java:410)
at
org.jboss.weld.module.ejb.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:134)
at
org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56)
at
org.jboss.weld.module.ejb.InjectionPointPropagatingEnterpriseTargetBeanInstance.invoke(InjectionPointPropagatingEnterpriseTargetBeanInstance.java:68)
at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:106)
at jdk.internal.reflect.GeneratedMethodAccessor221.invoke(Unknown Source)
at
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1/DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(java.base@11.0.1/Method.java:566)
at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140)
at
org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399)
at
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363)
at
org.jboss.resteasy.core.ResourceMethodInvoker$$Lambda$1165/0x0000000801da4040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
- locked <0x0000000710fa2020> (a
org.jboss.resteasy.core.interception.PostMatchContainerRequestContext)
at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337)
at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:310)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:443)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:233)
at
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$1160/0x0000000801da6c40.run(Unknown
Source)
at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:139)
at
org.jboss.resteasy.core.SynchronousDispatcher$$Lambda$1161/0x0000000801da6040.get(Unknown
Source)
at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
- locked <0x0000000710fa2078> (a
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext)
at
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:142)
at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:219)
at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at
io.opentracing.contrib.jaxrs2.server.SpanFinishingFilter.doFilter(SpanFinishingFilter.java:55)
at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
at
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
at
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at
org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
at
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
at
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
at
io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
at
io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
at
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction$$Lambda$1063/0x000000080183d840.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction$$Lambda$1064/0x000000080183dc40.call(Unknown
Source)
at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
at
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)
Locked ownable synchronizers:
- None
And all other task threads from Wildfly were at some state like this:
"default task-22" #353 prio=5 os_prio=0 cpu=1166.75ms elapsed=27.62s
allocated=31M defined_classes=18 tid=0x00000000033d5000 nid=0x75a1 waiting on condition
[0x00007f92af453000]
java.lang.Thread.State: WAITING (parking)
at jdk.internal.misc.Unsafe.park(java.base(a)11.0.1/Native Method)
- parking to wait for <0x000000068d11c178> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(java.base@11.0.1/LockSupport.java:194)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.1/AbstractQueuedSynchronizer.java:885)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1009)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.1/AbstractQueuedSynchronizer.java:1324)
at
java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.1/ReentrantReadWriteLock.java:738)
at
org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:544)
at
org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:219)
at
org.infinispan.persistence.PersistenceUtil.lambda$loadAndComputeInDataContainer$1(PersistenceUtil.java:179)
at
org.infinispan.persistence.PersistenceUtil$$Lambda$1207/0x0000000801e89040.compute(Unknown
Source)
at
org.infinispan.container.impl.AbstractInternalDataContainer.lambda$compute$3(AbstractInternalDataContainer.java:223)
at
org.infinispan.container.impl.AbstractInternalDataContainer$$Lambda$1208/0x0000000801e89c40.apply(Unknown
Source)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache.lambda$remap$16(BoundedLocalCache.java:2199)
at
com.github.benmanes.caffeine.cache.BoundedLocalCache$$Lambda$1209/0x0000000801e8a440.apply(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.compute(java.base@11.0.1/ConcurrentHashMap.java:1908)
- locked <0x0000000710d8d910> (a
java.util.concurrent.ConcurrentHashMap$ReservationNode)
Here is my understanding:
1. "default task-6" locked "0x0000000719600070", then waiting for the
read lock in "PersistenceManagerImpl".
2. "expiration-thread--p9-t1" grabbed read lock (based on the source code, it
must have grabbed the read lock in order to reach locking "0x0000000719600070"),
then waiting to lock "0x0000000719600070".
3. "persistence-thread--p11-t4" would like to grab the write lock in order to
continue.
4. "PersistenceManagerImpl" uses "NonfairSync", based on this
implementation in "ReentrantReadWriteLock" in openJDK-11.0.1
{code:java}
/**
* Nonfair version of Sync
*/
static final class NonfairSync extends Sync {
private static final long serialVersionUID = -8159625535654395037L;
final boolean writerShouldBlock() {
return false; // writers can always barge
}
final boolean readerShouldBlock() {
/* As a heuristic to avoid indefinite writer starvation,
* block if the thread that momentarily appears to be head
* of queue, if one exists, is a waiting writer. This is
* only a probabilistic effect since a new reader will not
* block if there is a waiting writer behind other enabled
* readers that have not yet drained from the queue.
*/
return apparentlyFirstQueuedIsExclusive();
}
}
{code}
It seems to me that the writer ("persistence-thread--p11-t4") has reached
the head of queue, so the reader "default task-6" cannot continue (in order not
to starve the writer). So the lock ("0x0000000719600070") locked by this this
reader "default task-6" cannot be released, which caused the reader thread
"expiration-thread--p9-t1" cannot continue. So here a deadlock was formed.
I here propose a way to avoid this deadlock by only using
"storesMutex.writeLock().tryLock()" in "pollStoreAvailability".
Also, Wildfly should provide a way to set "availabilityInterval".
--
This message was sent by Atlassian Jira
(v7.12.1#712002)