hazelcast icon indicating copy to clipboard operation
hazelcast copied to clipboard

Published 20 hours ago • verified publisher icon hazelcast

com.hazelcast.spring.cache.HazelcastCacheTest

Open olukas opened this issue 1 year ago • 8 comments

master (commit 4c9cd6ae7386dbde10450d5fd6bc14b71c59e37a)

Failed on corretto-17: https://jenkins.hazelcast.com/job/Hazelcast-master-CorrettoJDK17/119/testReport/com.hazelcast.spring.cache/HazelcastCacheTest/

Following tests failed:

  • com.hazelcast.spring.cache.HazelcastCacheTest.testCacheGetSynchronized
  • com.hazelcast.spring.cache.HazelcastCacheTest.testCacheGetCallable
  • com.hazelcast.spring.cache.HazelcastCacheTest.testCacheGetCallableWithNull
Stacktrace for testCacheGetSynchronized: 
java.lang.AssertionError: expected:<10> but was:<0>
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.failNotEquals(Assert.java:835)
	at org.junit.Assert.assertEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:633)
	at com.hazelcast.spring.cache.HazelcastCacheTest.testCacheGetSynchronized(HazelcastCacheTest.java:173)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
	at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
	at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
	at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
	at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.lang.Thread.run(Thread.java:833)
Stacktrace for testCacheGetCallable and testCacheGetCallableWithNull: 
com.hazelcast.core.OperationTimeoutException: GetOperation invocation failed to complete due to operation-heartbeat-timeout. Current time: 2023-12-15 00:31:30.100. Start time: 2023-12-15 00:29:29.125. Total elapsed time: 120975 ms. Last operation heartbeat: never. Last operation heartbeat from member: 2023-12-15 00:31:24.453. Invocation{op=com.hazelcast.map.impl.operation.GetOperation{serviceName='hz:impl:mapService', identityHash=183874857, partitionId=4, replicaIndex=0, callId=-24, invocationTime=1702600169125 (2023-12-15 00:29:29.125), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0, name=test}, tryCount=250, tryPauseMillis=500, invokeCount=1, callTimeoutMillis=60000, firstInvocationTimeMs=1702600169125, firstInvocationTime='2023-12-15 00:29:29.125', lastHeartbeatMillis=0, lastHeartbeatTime='1970-01-01 00:00:00.000', targetAddress=[127.0.0.1]:5701, targetMember=Member [127.0.0.1]:5701 - 84af2434-810f-4af3-92ff-59d728eb2402, memberListVersion=4, pendingResponse={VOID}, backupsAcksExpected=-1, backupsAcksReceived=0, connection=Connection[id=1, /127.0.0.1:42165->/127.0.0.1:5701, qualifier=null, endpoint=[127.0.0.1]:5701, remoteUuid=84af2434-810f-4af3-92ff-59d728eb2402, alive=true, connectionType=MEMBER, planeIndex=0]}
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.newOperationTimeoutException(InvocationFuture.java:203)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.toExceptionalResult(InvocationFuture.java:167)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolve(InvocationFuture.java:131)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolveAndThrowIfException(InvocationFuture.java:99)
	at com.hazelcast.spi.impl.AbstractInvocationFuture.get(AbstractInvocationFuture.java:618)
	at com.hazelcast.map.impl.proxy.MapProxySupport.invokeOperation(MapProxySupport.java:510)
	at com.hazelcast.map.impl.proxy.MapProxySupport.getInternal(MapProxySupport.java:419)
	at com.hazelcast.map.impl.proxy.MapProxyImpl.get(MapProxyImpl.java:122)
	at com.hazelcast.spring.cache.HazelcastCache.lookup(HazelcastCache.java:162)
	at com.hazelcast.spring.cache.HazelcastCache.get(HazelcastCache.java:67)
	at com.hazelcast.spring.cache.HazelcastCacheTest.doTestCacheGetCallable(HazelcastCacheTest.java:86)
	at com.hazelcast.spring.cache.HazelcastCacheTest.testCacheGetCallable(HazelcastCacheTest.java:74)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
	at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
	at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
	at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.lang.Thread.run(Thread.java:833)
	at ------ submitted from ------.()
	at com.hazelcast.internal.util.ExceptionUtil.cloneExceptionWithFixedAsyncStackTrace(ExceptionUtil.java:348)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.returnOrThrowWithGetConventions(InvocationFuture.java:112)
	at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.resolveAndThrowIfException(InvocationFuture.java:100)
	at com.hazelcast.spi.impl.AbstractInvocationFuture.get(AbstractInvocationFuture.java:618)
	at com.hazelcast.map.impl.proxy.MapProxySupport.invokeOperation(MapProxySupport.java:510)
	at com.hazelcast.map.impl.proxy.MapProxySupport.getInternal(MapProxySupport.java:419)
	at com.hazelcast.map.impl.proxy.MapProxyImpl.get(MapProxyImpl.java:122)
	at com.hazelcast.spring.cache.HazelcastCache.lookup(HazelcastCache.java:162)
	at com.hazelcast.spring.cache.HazelcastCache.get(HazelcastCache.java:67)
	at com.hazelcast.spring.cache.HazelcastCacheTest.doTestCacheGetCallable(HazelcastCacheTest.java:86)
	at com.hazelcast.spring.cache.HazelcastCacheTest.testCacheGetCallable(HazelcastCacheTest.java:74)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
	at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
	at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
	at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
	at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115)
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.lang.Thread.run(Thread.java:833)
Standard output for testCacheGetSynchronized: 
00:27:42,292  INFO || - [HealthMonitor] hz.HazelcastCacheReadTimeoutTestWithJavaConfig_clever_grothendieck.HealthMonitor - [127.0.0.1]:5702 [dev] [5.4.0-SNAPSHOT] processors=8, physical.memory.total=754.6G, physical.memory.free=303.1G, swap.space.total=8.0G, swap.space.free=7.8G, heap.memory.used=382.8M, heap.memory.free=7.6G, heap.memory.total=8.0G, heap.memory.max=8.0G, heap.memory.used/total=4.67%, heap.memory.used/max=4.67%, minor.gc.count=5, minor.gc.time=189ms, major.gc.count=0, major.gc.time=0ms, load.process=0.21%, load.system=76.60%, load.systemAverage=10.18, thread.count=63, thread.peakCount=424, cluster.timeDiff=-4, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=85, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=10, proxy.count=11, clientEndpoint.count=0, connection.active.count=1, client.connection.count=0, connection.count=1
00:29:02,298  INFO || - [HealthMonitor] hz.HazelcastCacheReadTimeoutTestWithJavaConfig_clever_grothendieck.HealthMonitor - [127.0.0.1]:5702 [dev] [5.4.0-SNAPSHOT] processors=8, physical.memory.total=754.6G, physical.memory.free=304.0G, swap.space.total=8.0G, swap.space.free=7.8G, heap.memory.used=398.7M, heap.memory.free=7.6G, heap.memory.total=8.0G, heap.memory.max=8.0G, heap.memory.used/total=4.87%, heap.memory.used/max=4.87%, minor.gc.count=5, minor.gc.time=189ms, major.gc.count=0, major.gc.time=0ms, load.process=0.63%, load.system=83.94%, load.systemAverage=9.95, thread.count=63, thread.peakCount=424, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=102, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=10, proxy.count=11, clientEndpoint.count=0, connection.active.count=1, client.connection.count=0, connection.count=1
00:29:29,104  INFO || - [InvocationMonitor] hz.HazelcastCacheReadTimeoutTestWithJavaConfig_clever_grothendieck.InvocationMonitorThread - [127.0.0.1]:5702 [dev] [5.4.0-SNAPSHOT] Invocations:10 timeouts:10 backup-timeouts:0 member-left: 0
Standard output for testCacheGetCallable and testCacheGetCallableWithNull: 
00:29:42,301  INFO || - [HealthMonitor] hz.HazelcastCacheReadTimeoutTestWithJavaConfig_clever_grothendieck.HealthMonitor - [127.0.0.1]:5702 [dev] [5.4.0-SNAPSHOT] processors=8, physical.memory.total=754.6G, physical.memory.free=303.6G, swap.space.total=8.0G, swap.space.free=7.8G, heap.memory.used=407.9M, heap.memory.free=7.6G, heap.memory.total=8.0G, heap.memory.max=8.0G, heap.memory.used/total=4.98%, heap.memory.used/max=4.98%, minor.gc.count=5, minor.gc.time=189ms, major.gc.count=0, major.gc.time=0ms, load.process=0.10%, load.system=78.57%, load.systemAverage=8.40, thread.count=53, thread.peakCount=424, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=121, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=1, proxy.count=9, clientEndpoint.count=0, connection.active.count=1, client.connection.count=0, connection.count=1
00:31:30,100  INFO || - [InvocationMonitor] hz.HazelcastCacheReadTimeoutTestWithJavaConfig_clever_grothendieck.InvocationMonitorThread - [127.0.0.1]:5702 [dev] [5.4.0-SNAPSHOT] Invocations:1 timeouts:1 backup-timeouts:0 member-left: 0

Standard output can be found here - https://s3.console.aws.amazon.com/s3/buckets/j-artifacts/Hazelcast-master-CorrettoJDK17/119/

olukas avatar Dec 15 '23 12:12 olukas

Failed again on master with corretto-21: https://jenkins.hazelcast.com/job/Hazelcast-master-CorrettoJDK21/1/testReport/com.hazelcast.spring.cache/HazelcastCacheTest/

Patras3 avatar Jan 30 '24 16:01 Patras3

Failed again on master with RedHatJDK17: https://jenkins.hazelcast.com/view/Official%20Builds/job/Hazelcast-master-RedHatJDK17/104/testReport/com.hazelcast.spring.cache/HazelcastCacheTest/

olukas avatar Feb 13 '24 07:02 olukas

Failed again on master with openjdk-17 (MacOS): https://jenkins.hazelcast.com/job/Hazelcast-master-MacOS-OpenJDK17/6/testReport/junit/com.hazelcast.spring.cache/HazelcastCacheTest/testCacheGetSynchronized/

sumnerib avatar Feb 20 '24 17:02 sumnerib

Failed again on master with OpenJDK17: https://jenkins.hazelcast.com/job/Hazelcast-master-OpenJDK17-Esxi7/80/testReport/com.hazelcast.spring.cache/HazelcastCacheTest/

olukas avatar Mar 11 '24 07:03 olukas

Failed again on master with MacOS - ZuluJDK21: https://jenkins.hazelcast.com/view/Official%20Builds/job/Hazelcast-master-MacOS-ZuluJDK21/26/testReport/junit/com.hazelcast.spring.cache/HazelcastCacheTest/testCacheGetSynchronized/

AleksPeychev avatar Apr 01 '24 18:04 AleksPeychev

Failed again on 5.4.z with oracle-17 (little-endian): https://jenkins.hazelcast.com/view/Official%20Builds/job/Hazelcast-5.maintenance-little-endian/306/testReport/junit/com.hazelcast.spring.cache/HazelcastCacheTest/testCacheGetSynchronized/

AleksPeychev avatar Jun 05 '24 14:06 AleksPeychev

Failed again on master with oracle-17 (force-offload): https://jenkins.hazelcast.com/job/Hazelcast-master-force-offload/106/testReport/com.hazelcast.spring.cache/HazelcastCacheTest/testCacheGetSynchronized/

olukas avatar Jul 10 '24 07:07 olukas