]
Dan Berindei commented on ISPN-11172:
-------------------------------------
I found an exception in the container output:
{noformat}
18:15:05,923 WARN (jgroups-8,05ea2c1c87a5-30319) [CLUSTER] ISPN000071: Caught exception
when handling command CacheTopologyControlCommand{cache=___script_cache,
type=SHUTDOWN_REQUEST, sender=null, joinInfo=null, topologyId=0, rebalanceId=0,
currentCH=null, pendingCH=null, availabilityMode=null, phase=null, actualMembers=null,
throwable=null, viewId=0} org.infinispan.remoting.RemoteException: ISPN000217: Received
exception from 05ea2c1c87a5-30319, see cause for remote stack trace
at
org.infinispan.remoting.transport.ResponseCollectors.wrapRemoteException(ResponseCollectors.java:25)
at
org.infinispan.remoting.transport.impl.VoidResponseCollector.addException(VoidResponseCollector.java:46)
at
org.infinispan.remoting.transport.impl.VoidResponseCollector.addException(VoidResponseCollector.java:18)
at
org.infinispan.remoting.transport.ValidResponseCollector.addResponse(ValidResponseCollector.java:29)
at
org.infinispan.topology.TopologyManagementHelper.lambda$addLocalResult$2(TopologyManagementHelper.java:135)
at
java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:930)
at
java.base/java.util.concurrent.CompletableFuture.uniHandleStage(CompletableFuture.java:946)
at java.base/java.util.concurrent.CompletableFuture.handle(CompletableFuture.java:2266)
at
org.infinispan.topology.TopologyManagementHelper.lambda$addLocalResult$3(TopologyManagementHelper.java:131)
at
java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072)
at
java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at
java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
at org.infinispan.remoting.transport.AbstractRequest.complete(AbstractRequest.java:67)
at
org.infinispan.remoting.transport.impl.MultiTargetRequest.onResponse(MultiTargetRequest.java:104)
at
org.infinispan.remoting.transport.impl.RequestRepository.addResponse(RequestRepository.java:52)
at
org.infinispan.remoting.transport.jgroups.JGroupsTransport.processResponse(JGroupsTransport.java:1411)
at
org.infinispan.remoting.transport.jgroups.JGroupsTransport.processMessage(JGroupsTransport.java:1314)
at
org.infinispan.remoting.transport.jgroups.JGroupsTransport.access$300(JGroupsTransport.java:129)
at
org.infinispan.remoting.transport.jgroups.JGroupsTransport$ChannelCallbacks.up(JGroupsTransport.java:1459)
at org.jgroups.JChannel.up(JChannel.java:775)
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:920)
at org.jgroups.protocols.FlowControl.up(FlowControl.java:338)
at org.jgroups.protocols.FlowControl.up(FlowControl.java:338)
at org.jgroups.protocols.tom.TOA.up(TOA.java:119)
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:859)
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:243)
at org.jgroups.protocols.UNICAST3.deliverMessage(UNICAST3.java:1049)
at org.jgroups.protocols.UNICAST3.addMessage(UNICAST3.java:772)
at org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:753)
at org.jgroups.protocols.UNICAST3.up(UNICAST3.java:405)
at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:592)
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:132)
at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:205)
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:254)
at org.jgroups.protocols.MERGE3.up(MERGE3.java:285)
at org.jgroups.protocols.Discovery.up(Discovery.java:300)
at org.jgroups.protocols.TP.passMessageUp(TP.java:1367)
at
org.jgroups.util.SubmitToThreadPool$SingleMessageHandler.run(SubmitToThreadPool.java:89)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from
05ea2c1c87a5-30319, see cause for remote stack trace
at
org.infinispan.topology.TopologyManagementHelper.makeResponse(TopologyManagementHelper.java:144)
at
org.infinispan.topology.TopologyManagementHelper.lambda$addLocalResult$2(TopologyManagementHelper.java:132)
... 36 more
Caused by: java.lang.NullPointerException
at
org.infinispan.topology.LocalTopologyManagerImpl.handleCacheShutdown(LocalTopologyManagerImpl.java:743)
at
org.infinispan.topology.CacheTopologyControlCommand.doPerform(CacheTopologyControlCommand.java:189)
at
org.infinispan.topology.CacheTopologyControlCommand.invokeAsync(CacheTopologyControlCommand.java:160)
at
org.infinispan.topology.TopologyManagementHelper.executeOnClusterSync(TopologyManagementHelper.java:54)
at
org.infinispan.topology.ClusterTopologyManagerImpl.broadcastShutdownCache(ClusterTopologyManagerImpl.java:734)
at
org.infinispan.topology.ClusterCacheStatus.shutdownCache(ClusterCacheStatus.java:951)
at
org.infinispan.topology.ClusterTopologyManagerImpl.handleShutdownRequest(ClusterTopologyManagerImpl.java:749)
at
org.infinispan.topology.CacheTopologyControlCommand.doPerform(CacheTopologyControlCommand.java:174)
at
org.infinispan.topology.CacheTopologyControlCommand.invokeAsync(CacheTopologyControlCommand.java:160)
at
org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler$ReplicableCommandRunner.run(GlobalInboundInvocationHandler.java:160)
at
org.infinispan.util.concurrent.BlockingTaskAwareExecutorServiceImpl$RunnableWrapper.run(BlockingTaskAwareExecutorServiceImpl.java:215)
... 3 more
{noformat}
We need to do more to ensure that any remote commands processed during shutdown return a
{{CacheNotFoundResponse}} instead of throwing random exceptions.
GracefulShutdownRestartIT fails
-------------------------------
Key: ISPN-11172
URL:
https://issues.redhat.com/browse/ISPN-11172
Project: Infinispan
Issue Type: Bug
Affects Versions: 10.1.0.Final
Reporter: Tristan Tarrant
Assignee: Tristan Tarrant
Priority: Major
{noformat}
Error Message
Cluster did not shutdown within timeout
Stacktrace
java.lang.AssertionError: Cluster did not shutdown within timeout
at org.infinispan.commons.util.Eventually.lambda$eventually$0(Eventually.java:33)
at org.infinispan.commons.util.Eventually.eventually(Eventually.java:25)
at org.infinispan.commons.util.Eventually.eventually(Eventually.java:33)
at
org.infinispan.server.resilience.GracefulShutdownRestartIT.testGracefulShutdownRestart(GracefulShutdownRestartIT.java:50)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.infinispan.server.test.InfinispanServerTestMethodRule$1.evaluate(InfinispanServerTestMethodRule.java:69)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at
org.infinispan.server.test.InfinispanServerRule$1.evaluate(InfinispanServerRule.java:90)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.junit.runners.Suite.runChild(Suite.java:128)
at org.junit.runners.Suite.runChild(Suite.java:27)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.apache.maven.surefire.junitcore.JUnitCore.run(JUnitCore.java:55)
at
org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:137)
at
org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:107)
at
org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:83)
at
org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:75)
at
org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:158)
at
org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
at
org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
Standard Output
[OK: 131, KO: 0, SKIP: 0] Test starting:
GracefulShutdownRestartIT.testGracefulShutdownRestart
[0] STDOUT: 12:36:05,513 WARN (async-thread--p2-t6) [CONFIG] ISPN000564: Configured
store 'SingleFileStore' is segmented and may use a large number of file
descriptors[m
[0] STDOUT: 12:36:05,514 WARN (async-thread--p2-t6) [CONFIG] ISPN000149: Fetch
persistent state and purge on startup are both disabled, cache may contain stale entries
on startup[m
[0] STDOUT: 12:36:05,515 WARN (async-thread--p2-t6) [CONFIG] ISPN000149: Fetch
persistent state and purge on startup are both disabled, cache may contain stale entries
on startup[m
[1] STDOUT: 12:36:05,558 WARN (remote-thread--p3-t2) [CONFIG] ISPN000564: Configured
store 'SingleFileStore' is segmented and may use a large number of file
descriptors[m
[1] STDOUT: 12:36:05,560 WARN (remote-thread--p3-t2) [CONFIG] ISPN000149: Fetch
persistent state and purge on startup are both disabled, cache may contain stale entries
on startup[m
[1] STDOUT: 12:36:05,562 WARN (remote-thread--p3-t2) [CONFIG] ISPN000149: Fetch
persistent state and purge on startup are both disabled, cache may contain stale entries
on startup[m
[0] STDOUT: 12:36:05,771 WARN (jgroups-13,06978f4151c0-63390) [CONFIG] ISPN000149: Fetch
persistent state and purge on startup are both disabled, cache may contain stale entries
on startup[m
[0] STDOUT: 12:36:05,776 WARN (jgroups-13,06978f4151c0-63390) [CONFIG] ISPN000149: Fetch
persistent state and purge on startup are both disabled, cache may contain stale entries
on startup[m
[0] STDOUT: 12:36:05,883 INFO (transport-thread--p5-t7) [CLUSTER]
[Context=C3F31F9D169B25D0C68FE5A26A6600FFA0E2E3F4]ISPN100002: Starting rebalance with
members [63781b79183e-43839, 06978f4151c0-63390], phase READ_OLD_WRITE_ALL, topology id
2[m
[0] STDOUT: 12:36:05,963 INFO (remote-thread--p3-t1) [CLUSTER]
[Context=C3F31F9D169B25D0C68FE5A26A6600FFA0E2E3F4]ISPN100009: Advancing to rebalance phase
READ_ALL_WRITE_ALL, topology id 3[m
[0] STDOUT: 12:36:05,978 INFO (remote-thread--p3-t1) [CLUSTER]
[Context=C3F31F9D169B25D0C68FE5A26A6600FFA0E2E3F4]ISPN100009: Advancing to rebalance phase
READ_NEW_WRITE_ALL, topology id 4[m
[0] STDOUT: 12:36:05,985 INFO (async-thread--p2-t17) [CLUSTER]
[Context=C3F31F9D169B25D0C68FE5A26A6600FFA0E2E3F4]ISPN100010: Finished rebalance with
members [63781b79183e-43839, 06978f4151c0-63390], topology id 5[m
[0] STDERR: WARNING: An illegal reflective access operation has occurred
[0] STDERR: WARNING: Illegal reflective access by
protostream.com.google.protobuf.UnsafeUtil
(file:/opt/infinispan/lib/protostream-4.3.1.Final.jar) to field java.nio.Buffer.address
[0] STDERR: WARNING: Please consider reporting this to the maintainers of
protostream.com.google.protobuf.UnsafeUtil
[0] STDERR: WARNING: Use --illegal-access=warn to enable warnings of further illegal
reflective access operations
[0] STDERR: WARNING: All illegal access operations will be denied in a future release
[1] STDERR: WARNING: An illegal reflective access operation has occurred
[1] STDERR: WARNING: Illegal reflective access by
protostream.com.google.protobuf.UnsafeUtil
(file:/opt/infinispan/lib/protostream-4.3.1.Final.jar) to field java.nio.Buffer.address
[1] STDERR: WARNING: Please consider reporting this to the maintainers of
protostream.com.google.protobuf.UnsafeUtil
[1] STDERR: WARNING: Use --illegal-access=warn to enable warnings of further illegal
reflective access operations
[1] STDERR: WARNING: All illegal access operations will be denied in a future release
[0] STDOUT: 12:36:06,811 INFO (SINGLE_PORT-ServerIO-8-2) [CLUSTER]
[Context=___protobuf_metadata]ISPN100008: Updating cache members list
[63781b79183e-43839], topology id 6[m
[0] STDOUT: 12:36:06,860 INFO (SINGLE_PORT-ServerIO-8-2) [CLUSTER]
[Context=C3F31F9D169B25D0C68FE5A26A6600FFA0E2E3F4]ISPN100008: Updating cache members list
[63781b79183e-43839], topology id 6[m
[0] STDOUT: 12:36:06,898 INFO (SINGLE_PORT-ServerIO-8-2) [CLUSTER]
[Context=memcachedCache]ISPN100008: Updating cache members list [63781b79183e-43839],
topology id 6[m
[1] STDOUT: 12:36:06,904 WARN (remote-thread--p3-t2) [CLUSTER] ISPN000071: Caught
exception when handling command CacheTopologyControlCommand{cache=___script_cache,
type=SHUTDOWN_PERFORM, sender=null, joinInfo=null, topologyId=0, rebalanceId=0,
currentCH=null, pendingCH=null, availabilityMode=null, phase=null, actualMembers=null,
throwable=null, viewId=0} java.lang.NullPointerException
[1] STDOUT: at
org.infinispan.topology.LocalTopologyManagerImpl.handleCacheShutdown(LocalTopologyManagerImpl.java:743)
[1] STDOUT: at
org.infinispan.topology.CacheTopologyControlCommand.doPerform(CacheTopologyControlCommand.java:189)
[1] STDOUT: at
org.infinispan.topology.CacheTopologyControlCommand.invokeAsync(CacheTopologyControlCommand.java:160)
[1] STDOUT: at
org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler$ReplicableCommandRunner.run(GlobalInboundInvocationHandler.java:160)
[1] STDOUT: at
org.infinispan.util.concurrent.BlockingTaskAwareExecutorServiceImpl$RunnableWrapper.run(BlockingTaskAwareExecutorServiceImpl.java:215)
[1] STDOUT: at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[1] STDOUT: at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[1] STDOUT: at java.base/java.lang.Thread.run(Thread.java:834)
[1] STDOUT: [m
{noformat}