https://github.com/infinispan/infinispan/pull/1277
On 3 September 2012 12:02, Ales Justin <[email protected]> wrote: > Nah, this is still the problem of shutdown / terminated Lucene resources -- > ISPN-2253. > > You have my patch in my ispn-2253 branch, but you said you'll clean it up a > bit. ;-) > > -Ales > > On Sep 3, 2012, at 11:46 AM, Sanne Grinovero <[email protected]> wrote: > >> The thread waiting on: >> at >> org.hibernate.search.backend.impl.lucene.LuceneBackendQueueProcessor.applyWork(LuceneBackendQueueProcessor.java:97) >> is legit, it needs to wait on the Infinispan cache to be available to >> complete the write operations on the index, which writes on the >> Infinispan caches. >> >> I think this is basically the same problem as the other problem you reported. >> >> Sanne >> >> On 2 September 2012 20:39, Ales Justin <[email protected]> wrote: >>> Stack trace of the shutdown: >>> >>> "MSC service thread 1-1@1343" prio=5 tid=0xf nid=NA runnable >>> java.lang.Thread.State: RUNNABLE >>> at >>> org.hibernate.search.backend.impl.lucene.LuceneBackendQueueProcessor.close(LuceneBackendQueueProcessor.java:73) >>> at >>> org.hibernate.search.backend.impl.jgroups.JGroupsBackendQueueProcessor.close(JGroupsBackendQueueProcessor.java:89) >>> at >>> org.hibernate.search.indexes.impl.DirectoryBasedIndexManager.destroy(DirectoryBasedIndexManager.java:82) >>> at >>> org.hibernate.search.indexes.impl.IndexManagerHolder.stop(IndexManagerHolder.java:342) >>> - locked <0x2cbc> (a org.hibernate.search.indexes.impl.IndexManagerHolder) >>> at >>> org.hibernate.search.impl.ImmutableSearchFactory.close(ImmutableSearchFactory.java:178) >>> at >>> org.hibernate.search.impl.MutableSearchFactory.close(MutableSearchFactory.java:122) >>> at >>> org.infinispan.query.impl.LifecycleManager.cacheStopped(LifecycleManager.java:177) >>> at >>> org.infinispan.factories.ComponentRegistry.stop(ComponentRegistry.java:202) >>> at org.infinispan.CacheImpl.stop(CacheImpl.java:537) >>> at org.infinispan.CacheImpl.stop(CacheImpl.java:529) >>> at >>> org.infinispan.AbstractDelegatingCache.stop(AbstractDelegatingCache.java:348) >>> at >>> org.jboss.as.capedwarf.api.CapedwarfApiProxy.destroy(CapedwarfApiProxy.java:82) >>> at >>> org.jboss.as.capedwarf.api.CapedwarfListener.contextDestroyed(CapedwarfListener.java:58) >>> at >>> org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:3489) >>> at org.apache.catalina.core.StandardContext.stop(StandardContext.java:3999) >>> - locked <0x2cc3> (a org.apache.catalina.core.StandardContext) >>> at >>> org.jboss.as.web.deployment.WebDeploymentService.stop(WebDeploymentService.java:118) >>> - locked <0x2cc4> (a org.jboss.as.web.deployment.WebDeploymentService) >>> at >>> org.jboss.msc.service.ServiceControllerImpl$StopTask.stopService(ServiceControllerImpl.java:1911) >>> at >>> org.jboss.msc.service.ServiceControllerImpl$StopTask.run(ServiceControllerImpl.java:1874) >>> at >>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) >>> at >>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) >>> at java.lang.Thread.run(Thread.java:680) >>> >>> >>> On Sep 2, 2012, at 1:59 AM, Ales Justin <[email protected]> wrote: >>> >>> OK, debuged the problem -- quite similar to ISPN-2232. >>> >>> I'm reusing an existing cache -- via re-start. >>> >>> But that cache is first stopped -- transitioning all the way to >>> >>> LuceneBackendQueueProcessor::close >>> >>> which calls >>> >>> LuceneBackendResources::shutdown >>> >>> which does >>> >>> flushCloseExecutor( queueingExecutor ); >>> >>> meaning it stops / terminates queueingExecutor. >>> >>> But once cache is re-started the queueingExecutor is never re-initialized / >>> re-started. >>> >>> Hence this ThreadPoolExecutor code: >>> >>> public void execute(Runnable command) { >>> if (command == null) >>> throw new NullPointerException(); >>> if (poolSize >= corePoolSize || !addIfUnderCorePoolSize(command)) { >>> if (runState == RUNNING && workQueue.offer(command)) { >>> if (runState != RUNNING || poolSize == 0) >>> ensureQueuedTaskHandled(command); >>> } >>> else if (!addIfUnderMaximumPoolSize(command)) >>> reject(command); // is shutdown or saturated >>> } >>> } >>> >>> * runState == TERMINATED !! * >>> >>> simply puts out command into reject(). >>> And there is nothing to pick it up, as the executor is terminated. >>> >>> Imo, should be easy to replicate this in Ispn Query tests. >>> >>> -Ales >>> >>> On Sep 1, 2012, at 3:59 PM, Ales Justin <[email protected]> wrote: >>> >>> Any idea why this is parked and never goes fwd? >>> As this then blocks any next cache requests -- see blocked thread below. >>> Could it be the error below? >>> >>> This only happens when there is already an existing CapeDwarf app deployed. >>> * e.g. (to reproduce) >>> https://github.com/capedwarf/capedwarf-blue/blob/master/testsuite/src/test/java/org/jboss/test/capedwarf/testsuite/deployment/test/ManualMultipleAppsTestCase.java >>> >>> The same test exposed ISPN-2232. >>> >>> -Ales >>> >>> --- >>> >>> "http-/192.168.1.101:8080-1" daemon prio=5 tid=0000000002c05000 >>> nid=0xb1ec1000 waiting on condition [00000000b1ebf000] >>> java.lang.Thread.State: WAITING (parking) >>> at sun.misc.Unsafe.park(Native Method) >>> - parking to wait for <0000000005d3a340> (a >>> java.util.concurrent.FutureTask$Sync) >>> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) >>> at >>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) >>> at >>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:969) >>> at >>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1281) >>> at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:218) >>> at java.util.concurrent.FutureTask.get(FutureTask.java:83) >>> at >>> org.hibernate.search.backend.impl.lucene.LuceneBackendQueueProcessor.applyWork(LuceneBackendQueueProcessor.java:97) >>> at >>> org.hibernate.search.backend.impl.jgroups.JGroupsBackendQueueProcessor.applyWork(JGroupsBackendQueueProcessor.java:116) >>> at >>> org.hibernate.search.indexes.impl.DirectoryBasedIndexManager.performOperations(DirectoryBasedIndexManager.java:127) >>> at >>> org.hibernate.search.backend.impl.WorkQueuePerIndexSplitter.commitOperations(WorkQueuePerIndexSplitter.java:61) >>> at >>> org.hibernate.search.backend.impl.BatchedQueueingProcessor.performWorks(BatchedQueueingProcessor.java:96) >>> at >>> org.hibernate.search.backend.impl.PostTransactionWorkQueueSynchronization.afterCompletion(PostTransactionWorkQueueSynchronization.java:99) >>> at >>> com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.afterCompletion(SynchronizationImple.java:96) >>> at >>> com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.afterCompletion(TwoPhaseCoordinator.java:402) >>> - locked <0000000005d3afc8> (a java.lang.Object) >>> at >>> com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:103) >>> at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164) >>> at >>> com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165) >>> at >>> com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117) >>> at >>> com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) >>> at >>> org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1013) >>> at org.infinispan.CacheImpl.putIfAbsent(CacheImpl.java:714) >>> at org.infinispan.DecoratedCache.putIfAbsent(DecoratedCache.java:184) >>> at >>> org.infinispan.loaders.CacheLoaderManagerImpl.preload(CacheLoaderManagerImpl.java:223) >>> at sun.reflect.GeneratedMethodAccessor51.invoke(Unknown Source) >>> at >>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >>> at java.lang.reflect.Method.invoke(Method.java:597) >>> at >>> org.infinispan.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:236) >>> at >>> org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:891) >>> at >>> org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:641) >>> at >>> org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:630) >>> at >>> org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:533) >>> at >>> org.infinispan.factories.ComponentRegistry.start(ComponentRegistry.java:174) >>> at org.infinispan.CacheImpl.start(CacheImpl.java:519) >>> at >>> org.infinispan.AbstractDelegatingCache.start(AbstractDelegatingCache.java:343) >>> at >>> org.jboss.capedwarf.common.infinispan.InfinispanUtils.checkCache(InfinispanUtils.java:72) >>> at >>> org.jboss.capedwarf.common.infinispan.InfinispanUtils.getCache(InfinispanUtils.java:82) >>> - locked <0000000016847f08> (a $Proxy46) >>> at >>> org.jboss.capedwarf.common.infinispan.InfinispanUtils.getCache(InfinispanUtils.java:191) >>> at >>> org.jboss.capedwarf.datastore.AbstractDatastoreService.createStore(AbstractDatastoreService.java:66) >>> at >>> org.jboss.capedwarf.datastore.AbstractDatastoreService.<init>(AbstractDatastoreService.java:60) >>> at >>> org.jboss.capedwarf.datastore.JBossDatastoreService.<init>(JBossDatastoreService.java:56) >>> at >>> com.google.appengine.api.datastore.DatastoreServiceFactory.getDatastoreService(DatastoreServiceFactory.java) >>> at >>> org.jboss.capedwarf.log.JBossLogService.requestStarted(JBossLogService.java:215) >>> at >>> org.jboss.capedwarf.appidentity.GAEListener.requestInitialized(GAEListener.java:91) >>> at >>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) >>> at >>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) >>> at >>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) >>> at >>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:372) >>> at >>> org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) >>> at >>> org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:679) >>> at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:931) >>> at java.lang.Thread.run(Thread.java:680) >>> >>> "http-/192.168.1.101:8080-2" daemon prio=5 tid=0000000002bd2c00 >>> nid=0xb1fc3000 waiting for monitor entry [00000000b1fc2000] >>> java.lang.Thread.State: BLOCKED (on object monitor) >>> at >>> org.jboss.capedwarf.common.infinispan.InfinispanUtils.getCache(InfinispanUtils.java:81) >>> - waiting to lock <0000000016847f08> (a $Proxy46) >>> at >>> org.jboss.capedwarf.common.infinispan.InfinispanUtils.getCache(InfinispanUtils.java:191) >>> at >>> org.jboss.capedwarf.datastore.AbstractDatastoreService.createStore(AbstractDatastoreService.java:66) >>> at >>> org.jboss.capedwarf.datastore.AbstractDatastoreService.<init>(AbstractDatastoreService.java:60) >>> at >>> org.jboss.capedwarf.datastore.JBossDatastoreService.<init>(JBossDatastoreService.java:56) >>> at >>> com.google.appengine.api.datastore.DatastoreServiceFactory.getDatastoreService(DatastoreServiceFactory.java) >>> at >>> org.jboss.capedwarf.log.JBossLogService.requestStarted(JBossLogService.java:215) >>> at >>> org.jboss.capedwarf.appidentity.GAEListener.requestInitialized(GAEListener.java:91) >>> at >>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) >>> at >>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) >>> at >>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) >>> at >>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:372) >>> at >>> org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:877) >>> at >>> org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:679) >>> at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:931) >>> at java.lang.Thread.run(Thread.java:680) >>> >>> -- >>> >>> 15:46:57,905 ERROR [stderr] (CacheStartThread,null,LuceneIndexesData) >>> Exception in thread "CacheStartThread,null,LuceneIndexesData" >>> org.infinispan.CacheException: Unable to acquire lock on cache with name >>> LuceneIndexesData >>> 15:46:57,905 ERROR [stderr] (CacheStartThread,null,LuceneIndexesData) at >>> org.infinispan.manager.DefaultCacheManager.wireCache(DefaultCacheManager.java:680) >>> 15:46:57,906 ERROR [stderr] (CacheStartThread,null,LuceneIndexesData) at >>> org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:654) >>> 15:46:57,906 ERROR [stderr] (CacheStartThread,null,LuceneIndexesData) at >>> org.infinispan.manager.DefaultCacheManager.access$100(DefaultCacheManager.java:127) >>> 15:46:57,906 ERROR [stderr] (CacheStartThread,null,LuceneIndexesData) at >>> org.infinispan.manager.DefaultCacheManager$1.run(DefaultCacheManager.java:580) >>> 15:46:57,907 ERROR [stderr] (CacheStartThread,null,LuceneIndexesLocking) >>> Exception in thread "CacheStartThread,null,LuceneIndexesLocking" >>> org.infinispan.CacheException: Unable to acquire lock on cache with name >>> LuceneIndexesLocking >>> 15:46:57,907 ERROR [stderr] (CacheStartThread,null,LuceneIndexesLocking) at >>> org.infinispan.manager.DefaultCacheManager.wireCache(DefaultCacheManager.java:680) >>> 15:46:57,908 ERROR [stderr] (CacheStartThread,null,LuceneIndexesLocking) at >>> org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:654) >>> 15:46:57,908 ERROR [stderr] (CacheStartThread,null,LuceneIndexesLocking) at >>> org.infinispan.manager.DefaultCacheManager.access$100(DefaultCacheManager.java:127) >>> 15:46:57,908 ERROR [stderr] (CacheStartThread,null,LuceneIndexesLocking) at >>> org.infinispan.manager.DefaultCacheManager$1.run(DefaultCacheManager.java:580) >>> 15:46:57,910 INFO [org.jboss.as.clustering.infinispan] >>> (http-/192.168.1.101:8080-1) JBAS010281: Started LuceneIndexesMetadata cache >>> from capedwarf container >>> 15:46:57,912 INFO [org.jboss.as.clustering.infinispan] >>> (http-/192.168.1.101:8080-1) JBAS010281: Started LuceneIndexesData cache >>> from capedwarf container >>> 15:46:57,913 INFO [org.jboss.as.clustering.infinispan] >>> (http-/192.168.1.101:8080-1) JBAS010281: Started LuceneIndexesLocking cache >>> from capedwarf container >>> 15:46:57,914 INFO >>> [org.hibernate.search.indexes.serialization.avro.impl.AvroSerializationProvider] >>> (http-/192.168.1.101:8080-1) HSEARCH000079: Serialization protocol version >>> 1.0 >>> 15:46:57,915 ERROR [stderr] (CacheStartThread,null,LuceneIndexesMetadata) >>> Exception in thread "CacheStartThread,null,LuceneIndexesMetadata" >>> org.infinispan.CacheException: Unable to acquire lock on cache with name >>> LuceneIndexesMetadata >>> 15:46:57,916 ERROR [stderr] (CacheStartThread,null,LuceneIndexesMetadata) at >>> org.infinispan.manager.DefaultCacheManager.wireCache(DefaultCacheManager.java:680) >>> 15:46:57,916 ERROR [stderr] (CacheStartThread,null,LuceneIndexesMetadata) at >>> org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:654) >>> 15:46:57,916 ERROR [stderr] (CacheStartThread,null,LuceneIndexesMetadata) at >>> org.infinispan.manager.DefaultCacheManager.access$100(DefaultCacheManager.java:127) >>> 15:46:57,916 ERROR [stderr] (CacheStartThread,null,LuceneIndexesMetadata) at >>> org.infinispan.manager.DefaultCacheManager$1.run(DefaultCacheManager.java:580) >>> >>> >>> >>> > _______________________________________________ infinispan-dev mailing list [email protected] https://lists.jboss.org/mailman/listinfo/infinispan-dev
