[infinispan-issues] [JBoss JIRA] Resolved: (ISPN-697) Infinispan 4.1.0.FINAL hangs on program exit when creating an indexed cache backed by a FS store

Infinispan 4.1.0.FINAL hangs on program exit when creating an indexed cache backed by a FS store ------------------------------------------------------------------------------------------------ Key: ISPN-697 URL: https://jira.jboss.org/browse/ISPN-697 Project: Infinispan Issue Type: Bug Affects Versions: 4.0.0.Final, 4.1.0.Final, 4.2.0.ALPHA2 Environment: Windows Vista Business edition Core 2 Quad Centos Linux 5 P4 Mac OSX 10.6.4 Core 2 Duo Reporter: Craig Ching Assignee: Galder Zamarreño Attachments: infinispan-hang.tar.gz This is consistent across all the platforms mentioned in the "Environment" section. Either I end up with a hang on program exit, or I end up with an NPE. Here is a thread dump of of a java process that has hung: 2010-10-11 15:16:37 Full thread dump Java HotSpot(TM) Client VM (14.3-b01 mixed mode): "Hibernate Search: Directory writer-1" prio=6 tid=0x697ca800 nid=0x21d8 waiting on condition [0x6ac3f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0b446d38> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "Scheduled-eviction-thread-0" daemon prio=2 tid=0x697ca000 nid=0x2604 waiting on condition [0x6a33f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x0b396b60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925) at java.util.concurrent.DelayQueue.take(DelayQueue.java:160) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:583) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:576) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "pool-1-thread-5" prio=6 tid=0x6989b000 nid=0x207c in Object.wait() [0x69ddf000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at java.lang.Object.wait(Object.java:485) at hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:316) - locked <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:994) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1054) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "pool-1-thread-4" prio=6 tid=0x6989a000 nid=0x12b0 in Object.wait() [0x69d8f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at java.lang.Object.wait(Object.java:485) at hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:316) - locked <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:994) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1054) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "pool-1-thread-3" prio=6 tid=0x69898c00 nid=0xec0 in Object.wait() [0x69d3f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at java.lang.Object.wait(Object.java:485) at hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:316) - locked <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:994) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1054) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "pool-1-thread-2" prio=6 tid=0x69898800 nid=0x6ac in Object.wait() [0x69cef000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at java.lang.Object.wait(Object.java:485) at hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:316) - locked <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:994) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1054) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "pool-1-thread-1" prio=6 tid=0x6988fc00 nid=0x1cd8 in Object.wait() [0x69c9f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at java.lang.Object.wait(Object.java:485) at hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:316) - locked <0x0aa62820> (a hidden.edu.emory.mathcs.backport.java.util.concurrent.LinkedBlockingQueue$SerializableLock) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:994) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1054) at hidden.edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:575) at java.lang.Thread.run(Thread.java:619) Locked ownable synchronizers: - None "Low Memory Detector" daemon prio=6 tid=0x00c19c00 nid=0x25bc runnable [0x00000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "CompilerThread0" daemon prio=10 tid=0x00c05000 nid=0x2610 waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Attach Listener" daemon prio=10 tid=0x00c04800 nid=0x133c waiting on condition [0x00000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Signal Dispatcher" daemon prio=10 tid=0x00bfc000 nid=0x26a0 runnable [0x00000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Finalizer" daemon prio=8 tid=0x00bc9c00 nid=0x190c in Object.wait() [0x0128f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0a944108> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) - locked <0x0a944108> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) Locked ownable synchronizers: - None "Reference Handler" daemon prio=10 tid=0x00bc8800 nid=0x1cfc in Object.wait() [0x0123f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0a944190> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:485) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) - locked <0x0a944190> (a java.lang.ref.Reference$Lock) Locked ownable synchronizers: - None "main" prio=6 tid=0x000bb000 nid=0x145c in Object.wait() [0x0012f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0b46e418> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1143) - locked <0x0b46e418> (a java.lang.Thread) at org.codehaus.mojo.exec.ExecJavaMojo.joinThread(ExecJavaMojo.java:417) at org.codehaus.mojo.exec.ExecJavaMojo.joinNonDaemonThreads(ExecJavaMojo.java:407) at org.codehaus.mojo.exec.ExecJavaMojo.execute(ExecJavaMojo.java:311) at org.apache.maven.plugin.DefaultPluginManager.executeMojo(DefaultPluginManager.java:490) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoals(DefaultLifecycleExecutor.java:694) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeStandaloneGoal(DefaultLifecycleExecutor.java:569) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoal(DefaultLifecycleExecutor.java:539) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeGoalAndHandleFailures(DefaultLifecycleExecutor.java:387) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.executeTaskSegments(DefaultLifecycleExecutor.java:348) at org.apache.maven.lifecycle.DefaultLifecycleExecutor.execute(DefaultLifecycleExecutor.java:180) at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:328) at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:138) at org.apache.maven.cli.MavenCli.main(MavenCli.java:362) at org.apache.maven.cli.compat.CompatibleMain.main(CompatibleMain.java:60) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.codehaus.classworlds.Launcher.launchEnhanced(Launcher.java:315) at org.codehaus.classworlds.Launcher.launch(Launcher.java:255) at org.codehaus.classworlds.Launcher.mainWithExitCode(Launcher.java:430) at org.codehaus.classworlds.Launcher.main(Launcher.java:375) Locked ownable synchronizers: - None "VM Thread" prio=10 tid=0x00bc4400 nid=0x249c runnable "VM Periodic Task Thread" prio=10 tid=0x00c1ac00 nid=0x2300 waiting on condition JNI global references: 1197 And here is the stack back-trace when I get the NPE: 2010-10-11 15:55:27,305 ERROR [Scheduled-eviction-thread-0] (FileCacheStore.java:184) - Error while reading from file: /home/cching/dev/infinispan-hang/./store/Users/-202784536 java.lang.NullPointerException at org.infinispan.marshall.jboss.ConstantObjectTable.readObject(ConstantObjectTable.java:253) at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:357) at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:207) at org.jboss.marshalling.AbstractUnmarshaller.readObject(AbstractUnmarshaller.java:85) at org.infinispan.marshall.jboss.GenericJBossMarshaller.objectFromObjectStream(GenericJBossMarshaller.java:162) at org.infinispan.marshall.VersionAwareMarshaller.objectFromObjectStream(VersionAwareMarshaller.java:179) at org.infinispan.loaders.file.FileCacheStore.objectFromInputStreamInReentrantMode(FileCacheStore.java:262) at org.infinispan.loaders.file.FileCacheStore.loadBucket(FileCacheStore.java:181) at org.infinispan.loaders.file.FileCacheStore.purgeInternal(FileCacheStore.java:161) at org.infinispan.loaders.AbstractCacheStore$2.run(AbstractCacheStore.java:84) at org.infinispan.util.concurrent.WithinThreadExecutor.execute(WithinThreadExecutor.java:47) at org.infinispan.loaders.AbstractCacheStore.purgeExpired(AbstractCacheStore.java:81) at org.infinispan.eviction.EvictionManagerImpl.processEviction(EvictionManagerImpl.java:115) at org.infinispan.eviction.EvictionManagerImpl$ScheduledTask.run(EvictionManagerImpl.java:136) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205) 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:619) 2010-10-11 15:55:27,313 ERROR [Scheduled-eviction-thread-0] (AbstractCacheStore.java:86) - Problems encountered while purging expired org.infinispan.loaders.CacheLoaderException: Error while reading from file: /home/cching/dev/infinispan-hang/./store/Users/-202784536 at org.infinispan.loaders.file.FileCacheStore.loadBucket(FileCacheStore.java:185) at org.infinispan.loaders.file.FileCacheStore.purgeInternal(FileCacheStore.java:161) at org.infinispan.loaders.AbstractCacheStore$2.run(AbstractCacheStore.java:84) at org.infinispan.util.concurrent.WithinThreadExecutor.execute(WithinThreadExecutor.java:47) at org.infinispan.loaders.AbstractCacheStore.purgeExpired(AbstractCacheStore.java:81) at org.infinispan.eviction.EvictionManagerImpl.processEviction(EvictionManagerImpl.java:115) at org.infinispan.eviction.EvictionManagerImpl$ScheduledTask.run(EvictionManagerImpl.java:136) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205) 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:619) Caused by: java.lang.NullPointerException at org.infinispan.marshall.jboss.ConstantObjectTable.readObject(ConstantObjectTable.java:253) at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:357) at org.jboss.marshalling.river.RiverUnmarshaller.doReadObject(RiverUnmarshaller.java:207) at org.jboss.marshalling.AbstractUnmarshaller.readObject(AbstractUnmarshaller.java:85) at org.infinispan.marshall.jboss.GenericJBossMarshaller.objectFromObjectStream(GenericJBossMarshaller.java:162) at org.infinispan.marshall.VersionAwareMarshaller.objectFromObjectStream(VersionAwareMarshaller.java:179) at org.infinispan.loaders.file.FileCacheStore.objectFromInputStreamInReentrantMode(FileCacheStore.java:262) at org.infinispan.loaders.file.FileCacheStore.loadBucket(FileCacheStore.java:181) ... 15 more It seems like I'm able to get the NPE to happen more on my Linux system and the hang more on my Windows system, but both happen on both systems. I will attach a maven project that contains the code and the configuration I'm using. I don't yet run this clustered, so it's just a one node cache.