Clean up NullPointerExceptions in the core test logs ---------------------------------------------------- Key: ISPN-7977 URL: https://issues.jboss.org/browse/ISPN-7977 Project: Infinispan Issue Type: Task Components: Core, Test Suite - Core Affects Versions: 9.1.0.Beta1 Reporter: Dan Berindei Assignee: Dan Berindei Fix For: 9.3.0.CR1 Attachments: ClusterTopologyManagerImpl_NullPointerException.txt Even benign {{NullPointerException}} s are a bad smell, so tests should never trigger them. But they seem pretty common in the test logs nowadays. Some examples from the core test suite: {noformat} 23:30:26,503 ERROR (stateTransferExecutor-thread-SingleJoinTest[DIST_SYNC, tx=true]-NodeC-p583-t3:[StateRequest-dist]) [RpcManagerImpl] ISPN000073: Unexpected error while replicating java.lang.NullPointerException: null at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotelyAsync(JGroupsTransport.java:650) ~[classes/:?] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotelyAsync(RpcManagerImpl.java:127) ~[classes/:?] at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:168) ~[classes/:?] at org.infinispan.statetransfer.InboundTransferTask.requestSegments(InboundTransferTask.java:132) ~[classes/:?] at org.infinispan.statetransfer.StateConsumerImpl.lambda$addTransfer$7(StateConsumerImpl.java:1055) ~[classes/:?] at org.infinispan.executors.LimitedExecutor.lambda$executeAsync$1(LimitedExecutor.java:101) ~[classes/:?] at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144) [classes/:?] at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33) [classes/:?] at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174) [classes/:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121] {noformat} {noformat} 23:37:52,617 WARN (testng-AsynchronousInvocationTest:[]) [TrianglePerCacheInboundInvocationHandler] ISPN000071: Caught exception when handling command StreamRequestCommand{cacheName='___defaultcache'} java.lang.NullPointerException: null at org.infinispan.stream.impl.StreamRequestCommand.invokeAsync(StreamRequestCommand.java:89) ~[classes/:?] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:101) ~[classes/:?] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runSync(BaseBlockingRunnable.java:54) [classes/:?] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:38) [classes/:?] at org.infinispan.remoting.inboundhandler.TrianglePerCacheInboundInvocationHandler.handleDefaultCommand(TrianglePerCacheInboundInvocationHandler.java:183) [classes/:?] at org.infinispan.remoting.inboundhandler.TrianglePerCacheInboundInvocationHandler.handle(TrianglePerCacheInboundInvocationHandler.java:112) [classes/:?] at org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler.handleCacheRpcCommand(GlobalInboundInvocationHandler.java:120) [classes/:?] at org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler.handleFromCluster(GlobalInboundInvocationHandler.java:79) [classes/:?] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:175) [classes/:?] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:149) [classes/:?] at org.infinispan.remoting.AsynchronousInvocationTest.assertDispatchForCommand(AsynchronousInvocationTest.java:176) [test-classes/:?] at org.infinispan.remoting.AsynchronousInvocationTest.testCacheRpcCommands(AsynchronousInvocationTest.java:140) [test-classes/:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_121] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_121] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_121] at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84) [testng-6.8.8.jar:?] at org.testng.internal.Invoker.invokeMethod(Invoker.java:714) [testng-6.8.8.jar:?] at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901) [testng-6.8.8.jar:?] at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231) [testng-6.8.8.jar:?] at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127) [testng-6.8.8.jar:?] at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111) [testng-6.8.8.jar:?] at org.testng.TestRunner.privateRun(TestRunner.java:767) [testng-6.8.8.jar:?] at org.testng.TestRunner.run(TestRunner.java:617) [testng-6.8.8.jar:?] at org.testng.SuiteRunner.runTest(SuiteRunner.java:348) [testng-6.8.8.jar:?] at org.testng.SuiteRunner.access$000(SuiteRunner.java:38) [testng-6.8.8.jar:?] at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382) [testng-6.8.8.jar:?] at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64) [testng-6.8.8.jar:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121] {noformat} {noformat} 23:37:54,821 TRACE (ForkThread-2,ThreadLocalLeakTest:[]) [InvocationContextInterceptor] Exception while executing code, but we're shutting down so failing silently. org.infinispan.persistence.spi.PersistenceException: java.lang.NullPointerException at org.infinispan.persistence.file.SingleFileStore.write(SingleFileStore.java:365) ~[classes/:?] at org.infinispan.persistence.manager.PersistenceManagerImpl.lambda$writeToAllNonTxStores$9(PersistenceManagerImpl.java:518) ~[classes/:?] at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184) ~[?:1.8.0_121] at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175) ~[?:1.8.0_121] at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175) ~[?:1.8.0_121] at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1374) ~[?:1.8.0_121] at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) ~[?:1.8.0_121] at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[?:1.8.0_121] at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151) ~[?:1.8.0_121] at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174) ~[?:1.8.0_121] at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:1.8.0_121] at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418) ~[?:1.8.0_121] at org.infinispan.persistence.manager.PersistenceManagerImpl.writeToAllNonTxStores(PersistenceManagerImpl.java:518) ~[classes/:?] at org.infinispan.interceptors.impl.CacheWriterInterceptor.storeEntry(CacheWriterInterceptor.java:452) ~[classes/:?] at org.infinispan.interceptors.impl.CacheWriterInterceptor.lambda$visitPutKeyValueCommand$1(CacheWriterInterceptor.java:187) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(BaseAsyncInterceptor.java:109) ~[classes/:?] at org.infinispan.interceptors.impl.CacheWriterInterceptor.visitPutKeyValueCommand(CacheWriterInterceptor.java:179) ~[classes/:?] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58) ~[classes/:?] at org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitDataCommand(CacheLoaderInterceptor.java:208) ~[classes/:?] at org.infinispan.interceptors.impl.CacheLoaderInterceptor.visitPutKeyValueCommand(CacheLoaderInterceptor.java:135) ~[classes/:?] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenAccept(BaseAsyncInterceptor.java:102) ~[classes/:?] at org.infinispan.interceptors.impl.EntryWrappingInterceptor.setSkipRemoteGetsAndInvokeNextForDataCommand(EntryWrappingInterceptor.java:689) ~[classes/:?] at org.infinispan.interceptors.impl.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:310) ~[classes/:?] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndFinally(BaseAsyncInterceptor.java:154) ~[classes/:?] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:136) ~[classes/:?] at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:38) ~[classes/:?] at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:86) ~[classes/:?] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58) ~[classes/:?] at org.infinispan.interceptors.impl.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:197) ~[classes/:?] at org.infinispan.interceptors.impl.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:162) ~[classes/:?] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:74) ~[classes/:?] at org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:127) [classes/:?] at org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:97) [classes/:?] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:248) [classes/:?] at org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1606) [classes/:?] at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1271) [classes/:?] at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1720) [classes/:?] at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:276) [classes/:?] at org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:358) [classes/:?] at org.infinispan.cache.impl.EncoderCache.put(EncoderCache.java:652) [classes/:?] at org.infinispan.util.ThreadLocalLeakTest$2.run(ThreadLocalLeakTest.java:115) [test-classes/:?] at org.infinispan.test.AbstractInfinispanTest$RunnableWrapper.run(AbstractInfinispanTest.java:510) [test-classes/:?] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121] Caused by: java.lang.NullPointerException at org.infinispan.persistence.file.SingleFileStore.allocate(SingleFileStore.java:232) ~[classes/:?] at org.infinispan.persistence.file.SingleFileStore.write(SingleFileStore.java:332) ~[classes/:?] ... 46 more {noformat} {noformat} 23:38:21,145 ERROR (transport-thread-OptimisticTxFailureAfterLockingTest-NodeD-p33826-t2:[Topology-___defaultcache]) [LocalTopologyManagerImpl] ISPN000452: Failed to update topology for cache ___defaultcache java.lang.NullPointerException: null at org.infinispan.topology.PersistentUUIDManagerImpl.mapAddresses(PersistentUUIDManagerImpl.java:70) ~[classes/:?] at org.infinispan.topology.LocalTopologyManagerImpl.doHandleTopologyUpdate(LocalTopologyManagerImpl.java:348) ~[classes/:?] at org.infinispan.topology.LocalTopologyManagerImpl.lambda$handleTopologyUpdate$1(LocalTopologyManagerImpl.java:266) ~[classes/:?] at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144) [classes/:?] at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33) [classes/:?] at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174) [classes/:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121] {noformat} {noformat} 23:39:19,342 ERROR (transport-thread-ConcurrentStartChanelLookupTest-NodeA-p40485-t3:[Merge-1]) [ClusterCacheStatus] ISPN000228: Failed to recover cache repl state after the current node became the coordinator java.lang.NullPointerException: null at org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy.lambda$static$0(PreferAvailabilityStrategy.java:34) ~[classes/:?] at java.util.TimSort.countRunAndMakeAscending(TimSort.java:355) ~[?:1.8.0_121] at java.util.TimSort.sort(TimSort.java:220) ~[?:1.8.0_121] at java.util.Arrays.sort(Arrays.java:1512) ~[?:1.8.0_121] at java.util.stream.SortedOps$SizedRefSortingSink.end(SortedOps.java:348) ~[?:1.8.0_121] at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482) ~[?:1.8.0_121] at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[?:1.8.0_121] at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708) ~[?:1.8.0_121] at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:1.8.0_121] at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499) ~[?:1.8.0_121] at org.infinispan.partitionhandling.impl.PreferAvailabilityStrategy.onPartitionMerge(PreferAvailabilityStrategy.java:122) ~[classes/:?] at org.infinispan.topology.ClusterCacheStatus.doMergePartitions(ClusterCacheStatus.java:570) ~[classes/:?] at org.infinispan.topology.ClusterTopologyManagerImpl.lambda$recoverClusterStatus$4(ClusterTopologyManagerImpl.java:499) ~[classes/:?] at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144) [classes/:?] at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33) [classes/:?] at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174) [classes/:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121] {noformat}