hazelcast / hazelcast

Hazelcast is a unified real-time data platform combining stream processing with a fast data store, allowing customers to act instantly on data-in-motion for real-time insights.
https://www.hazelcast.com
Other
6.11k stars 1.83k forks source link

com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest.with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss [API-2028] [API-2219] #24275

Closed olukas closed 2 months ago

olukas commented 1 year ago

master (commit f7242148a89972cb339dbf927502859f3c2220dd)

Failed on redhat-8: https://jenkins.hazelcast.com/view/Official%20Builds/job/Hazelcast-master-RedHatJDK8/86/testReport/com.hazelcast.client.cache.impl.nearcache/ClientCacheNearCacheCacheOnUpdateTest/with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss/

Stacktrace: ``` java.lang.AssertionError: 100, NearCacheStatsImpl{ownedEntryCount=101, ownedEntryMemoryCost=11413, creationTime=1681440649914, hits=27073451, misses=49, ratio=55251940.8%, evictions=0, expirations=0, invalidations=9, invalidationRequests=13, lastPersistenceTime=0, persistenceCount=0, lastPersistenceDuration=0, lastPersistenceWrittenBytes=0, lastPersistenceKeyCount=0, lastPersistenceFailure=''}, NearCacheConfig{name=ClientCache, inMemoryFormat=BINARY, invalidateOnChange=true, timeToLiveSeconds=0, maxIdleSeconds=0, evictionConfig=EvictionConfig{size=2147483647, maxSizePolicy=ENTRY_COUNT, evictionPolicy=LRU, comparatorClassName=null, comparator=null}, cacheLocalEntries=false, localUpdatePolicy=CACHE_ON_UPDATE, preloaderConfig=NearCachePreloaderConfig{enabled=false, directory=, storeInitialDelaySeconds=600, storeIntervalSeconds=600}} expected:<0> but was:<49> 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 com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest.with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss(ClientCacheNearCacheCacheOnUpdateTest.java:67) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) 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 com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.lang.Thread.run(Thread.java:748) ```
Standard output: ``` Finished Running Test: with_invalidate_policy_concurrently_updated_near_cache_causes_misses in 11.105 seconds. 02:51:00,930 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [LifecycleService] Thread-24118 - hz.client_3479 [dev] [5.3.0-SNAPSHOT] HazelcastClient 5.3.0-SNAPSHOT (20230414 - f724214) is SHUTDOWN 02:51:00,930 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [LifecycleService] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] [127.0.0.1]:5701 is SHUTTING_DOWN 02:51:00,930 DEBUG |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [JobCoordinationService] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Added a shutting-down member: 8e16b837-5557-469f-882e-4f3296598f6a 02:51:00,930 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [MigrationManager] hz.ClientCacheNearCacheCacheOnUpdateTest_peaceful_blackburn.cached.thread-6 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Shutdown request of Member [127.0.0.1]:5701 - 8e16b837-5557-469f-882e-4f3296598f6a this is handled 02:51:00,931 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [Node] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Shutting down connection manager... 02:51:00,931 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [Node] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Shutting down node engine... 02:51:00,931 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [CacheService] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Removed cache config: CacheConfig{name='ClientCache', managerPrefix='/hz/', inMemoryFormat=BINARY, backupCount=1, hotRestart=HotRestartConfig{enabled=false, fsync=false}, dataPersistenceConfig=DataPersistenceConfig{enabled=false, fsync=false}, wanReplicationRef=null, merkleTreeConfig=MerkleTreeConfig{enabled=null, depth=10}} 02:51:00,934 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [NodeExtension] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Destroying node NodeExtension. 02:51:00,934 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [Node] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] Hazelcast Shutdown is completed in 4 ms. 02:51:00,934 INFO |with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss| - [LifecycleService] Thread-24118 - [127.0.0.1]:5701 [dev] [5.3.0-SNAPSHOT] [127.0.0.1]:5701 is SHUTDOWN BuildInfo right after with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss(com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest): BuildInfo{version='5.3.0-SNAPSHOT', build='20230414', buildNumber=20230414, revision=f724214, enterprise=false, serializationVersion=1} Hiccups measured while running test 'with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss(com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest):' 02:50:45, accumulated pauses: 1075 ms, max pause: 477 ms, pauses over 1000 ms: 0 02:50:50, accumulated pauses: 374 ms, max pause: 186 ms, pauses over 1000 ms: 0 02:50:55, accumulated pauses: 328 ms, max pause: 102 ms, pauses over 1000 ms: 0 02:51:00, accumulated pauses: 434 ms, max pause: 428 ms, pauses over 1000 ms: 0 No metrics recorded during the test ```

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

github-actions[bot] commented 1 year ago

Internal Jira issue: API-2028

olukas commented 1 year ago

Failed again on master with openjdk-20: https://jenkins.hazelcast.com/view/Official%20Builds/job/Hazelcast-master-OpenJDK-ea/33/testReport/com.hazelcast.client.cache.impl.nearcache/ClientCacheNearCacheCacheOnUpdateTest/with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss/

olukas commented 11 months ago

Reopening as issue occurred again on 5.3.z PR builder with oracle-11: https://jenkins.hazelcast.com/job/Hazelcast-pr-builder/21341/testReport/junit/com.hazelcast.client.cache.impl.nearcache/ClientCacheNearCacheCacheOnUpdateTest/with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss/

Stacktrace: ``` java.lang.AssertionError: 100, NearCacheStatsImpl{ownedEntryCount=101, ownedEntryMemoryCost=11413, creationTime=1698071849671, hits=53992877, misses=153, ratio=35289462.1%, evictions=0, expirations=0, invalidations=10, invalidationRequests=15, lastPersistenceTime=0, persistenceCount=0, lastPersistenceDuration=0, lastPersistenceWrittenBytes=0, lastPersistenceKeyCount=0, lastPersistenceFailure=''}, NearCacheConfig{name=ClientCache, inMemoryFormat=BINARY, invalidateOnChange=true, timeToLiveSeconds=0, maxIdleSeconds=0, evictionConfig=EvictionConfig{size=2147483647, maxSizePolicy=ENTRY_COUNT, evictionPolicy=LRU, comparatorClassName=null, comparator=null}, cacheLocalEntries=false, localUpdatePolicy=CACHE_ON_UPDATE, preloaderConfig=NearCachePreloaderConfig{enabled=false, directory=, storeInitialDelaySeconds=600, storeIntervalSeconds=600}} expected:<0> but was:<153> 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 com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest.with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss(ClientCacheNearCacheCacheOnUpdateTest.java:67) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) 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 com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.lang.Thread.run(Thread.java:750) ```
Standard output: ``` BuildInfo right after with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss(com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest): BuildInfo{version='5.3.5-SNAPSHOT', build='20231023', buildNumber=20231023, revision=a812005, enterprise=false, serializationVersion=1} Finished Running Test: with_invalidate_policy_concurrently_updated_near_cache_causes_misses in 13.364 seconds. Hiccups measured while running test 'with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss(com.hazelcast.client.cache.impl.nearcache.ClientCacheNearCacheCacheOnUpdateTest):' 14:37:25, accumulated pauses: 57 ms, max pause: 10 ms, pauses over 1000 ms: 0 14:37:30, accumulated pauses: 829 ms, max pause: 251 ms, pauses over 1000 ms: 0 14:37:35, accumulated pauses: 628 ms, max pause: 182 ms, pauses over 1000 ms: 0 14:37:40, accumulated pauses: 1438 ms, max pause: 1407 ms, pauses over 1000 ms: 1 No metrics recorded during the test ```

Standard output can be found here - https://s3.console.aws.amazon.com/s3/buckets/j-artifacts/Hazelcast-pr-builder/21341/

sumnerib commented 10 months ago

Failed again on master with microsoft-11: https://jenkins.hazelcast.com/job/Hazelcast-master-MicrosoftJDK11/90/testReport/junit/com.hazelcast.client.cache.impl.nearcache/ClientCacheNearCacheCacheOnUpdateTest/with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss/

Patras3 commented 10 months ago

Failed again on 5.3.z with oracle-8 (little-endian): https://jenkins.hazelcast.com/job/Hazelcast-5.maintenance-little-endian/278/testReport/junit/com.hazelcast.client.cache.impl.nearcache/ClientCacheNearCacheCacheOnUpdateTest/with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss/

Patras3 commented 8 months ago

Failed again on master with corretto-21: https://jenkins.hazelcast.com/job/Hazelcast-master-CorrettoJDK21/1/testReport/com.hazelcast.client.cache.impl.nearcache/ClientCacheNearCacheCacheOnUpdateTest/with_cacheOnUpdate_policy_concurrently_updated_near_cache_does_not_cause_any_miss/

github-actions[bot] commented 7 months ago

Internal Jira issue: API-2219

olukas commented 2 months ago

Closing the test failure - it doesn't seem to be related to master or the latest maintenance stream 5.5.z and it hasn't fail in the last 3 months. Feel free to reopen test failure if it occurs on master or on the latest maintenance stream.