github-actions[bot]
commented
3 months ago Internal Jira issue: HZ-4806
Closed Patras3 closed 2 months ago
github-actions[bot]
commented
3 months ago Internal Jira issue: HZ-4806
Fly-Style
commented
2 months ago
5.4.z (commit c2efaf3b29dfb8a3ed348db648df291b8723214b)
Failed on openj9-17: https://jenkins.hazelcast.com/job/Hazelcast-5.maintenance-Openj9-17/124/testReport/junit/com.hazelcast.jet.impl/JobSummaryTest/when_manyJobs_then_sortedBySubmissionTime_useOldJobSummary_true_/
Stacktrace:
``` java.lang.NullPointerException at java.base/java.lang.StringConcatHelper.simpleConcat(StringConcatHelper.java) at com.hazelcast.jet.core.JetTestSupport.lambda$assertJobStatusEventually$2(JetTestSupport.java:338) at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1200) at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1219) at com.hazelcast.jet.core.JetTestSupport.assertJobStatusEventually(JetTestSupport.java:337) at com.hazelcast.jet.core.JetTestSupport.assertJobStatusEventually(JetTestSupport.java:253) at com.hazelcast.jet.core.JetTestSupport.assertJobRunningEventually(JetTestSupport.java:300) at com.hazelcast.jet.impl.JobSummaryTest.when_manyJobs_then_sortedBySubmissionTime(JobSummaryTest.java:236) at java.base/java.lang.reflect.Method.invoke(Method.java:568) 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:857) ```Standard output:
``` Finished Running Test: when_batchJob[useOldJobSummary=true] in 0.239 seconds. Started Running Test: when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true] 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MetricsConfigHelper] Time-limited test - [LOCAL] [dev] [5.4.1-SNAPSHOT] Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1' 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [logo] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] o o o o---o o--o o o---o o o----o o--o--o | | / \ / | / / \ | | o----o o o o----o | o o o----o | | | * \ / | \ * \ | | o o * o o---o o--o o----o o---o * o o----o o 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Copyright (c) 2008-2024, Hazelcast, Inc. All Rights Reserved. 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Hazelcast Platform 5.4.1-SNAPSHOT (20240622) starting at [127.0.0.1]:5701 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Cluster name: dev 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Integrity Checker is disabled. Fail-fast on corrupted executables will not be performed. For more information, see the documentation for Integrity Checker. 10:55:17,643 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Jet is enabled 10:55:17,644 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MetricsConfigHelper] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled 10:55:17,648 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [CPSubsystem] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees. 10:55:17,651 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JetServiceBackend] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Setting number of cooperative threads and default parallelism to 2 10:55:17,651 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Diagnostics] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments. 10:55:17,651 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5701 is STARTING 10:55:17,651 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClusterService] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Members {size:1, ver:1} [ Member [127.0.0.1]:5701 - 48e087a8-2915-45ae-837d-b7d5b6320d96 this ] 10:55:17,651 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Jet started scanning for jobs 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5701 is STARTED 10:55:17,652 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Not starting jobs because partitions are not yet initialized. 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MetricsConfigHelper] Time-limited test - [LOCAL] [dev] [5.4.1-SNAPSHOT] Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1' 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [logo] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] o o o o---o o--o o o---o o o----o o--o--o | | / \ / | / / \ | | o----o o o o----o | o o o----o | | | * \ / | \ * \ | | o o * o o---o o--o o----o o---o * o o----o o 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Copyright (c) 2008-2024, Hazelcast, Inc. All Rights Reserved. 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Hazelcast Platform 5.4.1-SNAPSHOT (20240622) starting at [127.0.0.1]:5702 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Cluster name: dev 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Integrity Checker is disabled. Fail-fast on corrupted executables will not be performed. For more information, see the documentation for Integrity Checker. 10:55:17,652 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [system] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Jet is enabled 10:55:17,653 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MetricsConfigHelper] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled 10:55:17,656 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [CPSubsystem] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees. 10:55:17,658 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JetServiceBackend] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Setting number of cooperative threads and default parallelism to 2 10:55:17,659 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Diagnostics] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments. 10:55:17,659 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5702 is STARTING 10:55:17,659 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MockServer] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Created connection to endpoint: [127.0.0.1]:5701-48e087a8-2915-45ae-837d-b7d5b6320d96, connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5702, uuid=734825c3-0817-48ae-ba4a-27c90d755cd9], remoteEndpoint=[address=[127.0.0.1]:5701, uuid=48e087a8-2915-45ae-837d-b7d5b6320d96], alive=true} 10:55:17,659 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MockServer] hz.JobSummaryTest_stoic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Created connection to endpoint: [127.0.0.1]:5702-734825c3-0817-48ae-ba4a-27c90d755cd9, connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5701, uuid=48e087a8-2915-45ae-837d-b7d5b6320d96], remoteEndpoint=[address=[127.0.0.1]:5702, uuid=734825c3-0817-48ae-ba4a-27c90d755cd9], alive=true} 10:55:17,660 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClusterService] hz.JobSummaryTest_stoic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Members {size:2, ver:2} [ Member [127.0.0.1]:5701 - 48e087a8-2915-45ae-837d-b7d5b6320d96 this Member [127.0.0.1]:5702 - 734825c3-0817-48ae-ba4a-27c90d755cd9 ] 10:55:17,752 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-6 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Not starting jobs because partitions are not yet initialized. 10:55:17,760 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClusterService] hz.JobSummaryTest_elastic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Members {size:2, ver:2} [ Member [127.0.0.1]:5701 - 48e087a8-2915-45ae-837d-b7d5b6320d96 Member [127.0.0.1]:5702 - 734825c3-0817-48ae-ba4a-27c90d755cd9 this ] 10:55:17,760 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Jet started scanning for jobs 10:55:17,761 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5702 is STARTED 10:55:17,762 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AbstractConfigLocator] Time-limited test - Loading 'hazelcast-client-default.xml' from the classpath. 10:55:17,764 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AbstractXmlConfigHelper] Time-limited test - Name of the hazelcast schema location[http://www.hazelcast.com/schema/client-config/hazelcast-client-config-5.3.xsd] is incorrect, using default 10:55:17,771 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientInvocationService] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Running with 2 response threads, dynamic=true 10:55:17,772 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] HazelcastClient 5.4.1-SNAPSHOT (20240622) is STARTING 10:55:17,772 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] HazelcastClient 5.4.1-SNAPSHOT (20240622) is STARTED 10:55:17,774 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientConnectionManager] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Trying to connect to cluster: dev 10:55:17,774 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientConnectionManager] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Trying to connect to [127.0.0.1]:5702 10:55:17,774 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [HazelcastClient] Time-limited test - Created connection to endpoint: [127.0.0.1]:5702, connection: MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=true, connectionId=1, channel=null, remoteAddress=null, lastReadTime=never, lastWriteTime=never, closedTime=never}} 10:55:17,774 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AuthenticationMessageTask] hz.JobSummaryTest_elastic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Processing authentication with clientUuid 9c9800b8-d788-47de-8085-c16ec6c9f2fa and clientName hz.client_4464 10:55:17,774 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AuthenticationMessageTask] hz.JobSummaryTest_elastic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Received auth from MockedNodeConnection{ remoteAddress = [127.0.0.1]:40001, localAddress = [127.0.0.1]:5702, connectionId = 1}, successfully authenticated, clientUuid: 9c9800b8-d788-47de-8085-c16ec6c9f2fa, client name: hz.client_4464, client version: 5.4.1-SNAPSHOT 10:55:17,776 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientClusterService] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Members [2] { Member [127.0.0.1]:5701 - 48e087a8-2915-45ae-837d-b7d5b6320d96 Member [127.0.0.1]:5702 - 734825c3-0817-48ae-ba4a-27c90d755cd9 } 10:55:17,776 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] HazelcastClient 5.4.1-SNAPSHOT (20240622) is CLIENT_CONNECTED 10:55:17,776 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientConnectionManager] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Authenticated with server [127.0.0.1]:5702:734825c3-0817-48ae-ba4a-27c90d755cd9, server version: 5.4.1-SNAPSHOT, local address: /127.0.0.1:40001 10:55:17,776 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Diagnostics] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments. 10:55:17,776 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [HazelcastClient] Time-limited test - Created connection to endpoint: [127.0.0.1]:5701, connection: MockedClientConnection{localAddress=[127.0.0.1]:40002, super=ClientConnection{alive=true, connectionId=2, channel=null, remoteAddress=null, lastReadTime=never, lastWriteTime=never, closedTime=never}} 10:55:17,776 TRACE |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientListenerService] hz.client_4464.internal-1 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Register attempt of ClusterViewListenerHandler to MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=true, connectionId=1, channel=null, remoteAddress=[127.0.0.1]:5702, lastReadTime=2024-06-22 10:55:17.775, lastWriteTime=2024-06-22 10:55:17.774, closedTime=never}} 10:55:17,777 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AuthenticationMessageTask] hz.JobSummaryTest_stoic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Processing authentication with clientUuid 9c9800b8-d788-47de-8085-c16ec6c9f2fa and clientName hz.client_4464 10:55:17,777 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AuthenticationMessageTask] hz.JobSummaryTest_stoic_goldwasser.priority-generic-operation.thread-0 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Received auth from MockedNodeConnection{ remoteAddress = [127.0.0.1]:40002, localAddress = [127.0.0.1]:5701, connectionId = 2}, successfully authenticated, clientUuid: 9c9800b8-d788-47de-8085-c16ec6c9f2fa, client name: hz.client_4464, client version: 5.4.1-SNAPSHOT 10:55:17,778 TRACE |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientListenerService] ForkJoinPool.commonPool-worker-3 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Registered ClusterViewListenerHandler to MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=true, connectionId=1, channel=null, remoteAddress=[127.0.0.1]:5702, lastReadTime=2024-06-22 10:55:17.778, lastWriteTime=2024-06-22 10:55:17.776, closedTime=never}} 10:55:17,779 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientConnectionManager] Time-limited test - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Authenticated with server [127.0.0.1]:5701:48e087a8-2915-45ae-837d-b7d5b6320d96, server version: 5.4.1-SNAPSHOT, local address: /127.0.0.1:40002 10:55:17,780 TRACE |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientListenerService] hz.client_4464.eventRegistration- - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Register attempt of ClientListenerRegistration{codec=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$1@3b0e45f2, handler=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$BackupEventHandler@35fef780} to MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=true, connectionId=1, channel=null, remoteAddress=[127.0.0.1]:5702, lastReadTime=2024-06-22 10:55:17.778, lastWriteTime=2024-06-22 10:55:17.776, closedTime=never}} 10:55:17,780 TRACE |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientListenerService] hz.client_4464.eventRegistration- - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Registered ClientListenerRegistration{codec=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$1@3b0e45f2, handler=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$BackupEventHandler@35fef780} to MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=true, connectionId=1, channel=null, remoteAddress=[127.0.0.1]:5702, lastReadTime=2024-06-22 10:55:17.780, lastWriteTime=2024-06-22 10:55:17.780, closedTime=never}} 10:55:17,780 TRACE |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientListenerService] hz.client_4464.eventRegistration- - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Register attempt of ClientListenerRegistration{codec=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$1@3b0e45f2, handler=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$BackupEventHandler@35fef780} to MockedClientConnection{localAddress=[127.0.0.1]:40002, super=ClientConnection{alive=true, connectionId=2, channel=null, remoteAddress=[127.0.0.1]:5701, lastReadTime=2024-06-22 10:55:17.778, lastWriteTime=2024-06-22 10:55:17.777, closedTime=never}} 10:55:17,781 TRACE |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientListenerService] hz.client_4464.eventRegistration- - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Registered ClientListenerRegistration{codec=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$1@3b0e45f2, handler=com.hazelcast.client.impl.spi.impl.ClientInvocationServiceImpl$BackupEventHandler@35fef780} to MockedClientConnection{localAddress=[127.0.0.1]:40002, super=ClientConnection{alive=true, connectionId=2, channel=null, remoteAddress=[127.0.0.1]:5701, lastReadTime=2024-06-22 10:55:17.781, lastWriteTime=2024-06-22 10:55:17.780, closedTime=never}} 10:55:17,782 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientStatisticsService] Time-limited test - Client statistics is enabled with period 5 seconds. 10:55:17,783 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Planner] when_manyJobs_then_sortedBySubmissionTime - Watermarks in the pipeline will be throttled to 1000 10:55:17,783 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LightMasterContext] when_manyJobs_then_sortedBySubmissionTime - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Start executing light job 0be4-2460-45c0-0001, execution graph in DOT format: digraph DAG { "mapJournalSource(source)" [localParallelism=2]; "noop" [localParallelism=1]; "mapJournalSource(source)" -> "noop" [queueSize=1024]; } HINT: You can use graphviz or http://viz-js.com to visualize the printed graph. 10:55:17,783 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LightMasterContext] when_manyJobs_then_sortedBySubmissionTime - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Job config for 0be4-2460-45c0-0001: JobConfig {name=null, processingGuarantee=NONE, snapshotIntervalMillis=10000, autoScaling=true, suspendOnFailure=false, splitBrainProtectionEnabled=false, enableMetrics=true, storeMetricsAfterJobCompletion=false, resourceConfigs={}, serializerConfigs={}, arguments={}, classLoaderFactory=null, initialSnapshotName=null, maxProcessorAccumulatedRecords=-1, timeoutMillis=0} 10:55:17,783 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LightMasterContext] when_manyJobs_then_sortedBySubmissionTime - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Building execution plan for 0be4-2460-45c0-0001 10:55:17,784 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [PartitionStateManager] when_manyJobs_then_sortedBySubmissionTime - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Initializing cluster partition table arrangement... 10:55:17,784 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LightMasterContext] hz.JobSummaryTest_stoic_goldwasser.cached.thread-6 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Built execution plans for 0be4-2460-45c0-0001 10:55:17,784 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [InitExecutionOperation] hz.JobSummaryTest_stoic_goldwasser.cached.thread-6 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Initializing execution plan for job 0be4-2460-45c0-0001, execution 0be4-2460-45c0-0001 from [127.0.0.1]:5701 10:55:17,802 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [InitExecutionOperation] hz.JobSummaryTest_elastic_goldwasser.generic-operation.thread-0 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Initializing execution plan for job 0be4-2460-45c0-0001, execution 0be4-2460-45c0-0001 from [127.0.0.1]:5701 10:55:17,802 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobExecutionService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Execution plan for light job ID=0be4-2460-45c0-0001, jobName='0be4-2460-45c0-0001', executionId=0be4-2460-45c0-0001 initialized, will start the execution 10:55:17,802 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobExecutionService] hz.JobSummaryTest_elastic_goldwasser.cached.thread-4 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Execution plan for light job ID=0be4-2460-45c0-0001, jobName='0be4-2460-45c0-0001', executionId=0be4-2460-45c0-0001 initialized, will start the execution 10:55:17,809 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [AbstractJobProxy] Time-limited test - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Sending CANCEL_FORCEFUL request for job 0be4-2460-45c0-0001 (name ??) 10:55:17,809 DEBUG || - [JobExecutionService] ForkJoinPool.commonPool-worker-3 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Completed execution of job '0be4-2460-45c0-0001', execution 0be4-2460-45c0-0001 10:55:17,809 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobExecutionService] hz.JobSummaryTest_elastic_goldwasser.cached.thread-4 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Completed execution of job '0be4-2460-45c0-0001', execution 0be4-2460-45c0-0001 10:55:17,810 DEBUG |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobExecutionService] hz.JobSummaryTest_elastic_goldwasser.cached.thread-4 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Execution of job '0be4-2460-45c0-0001', execution 0be4-2460-45c0-0001 completed with failure java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:874) ~[?:?] at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162) ~[?:?] at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:72) ~[classes/:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:502) ~[classes/:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:433) ~[classes/:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:419) ~[classes/:?] at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:807) ~[?:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:373) ~[classes/:?] at java.base/java.lang.Thread.run(Thread.java:857) ~[?:?] Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:318) ~[classes/:?] at com.hazelcast.jet.impl.JobExecutionService.terminateExecution0(JobExecutionService.java:726) ~[classes/:?] at com.hazelcast.jet.impl.JobExecutionService.terminateExecution(JobExecutionService.java:722) ~[classes/:?] at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.doRun(TerminateExecutionOperation.java:59) ~[classes/:?] at com.hazelcast.jet.impl.operation.AsyncOperation.run(AsyncOperation.java:55) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:193) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:294) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:265) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:497) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:185) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:141) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.loop(OperationThread.java:134) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.executeRun(OperationThread.java:115) ~[classes/:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111) [classes/:?] 10:55:17,809 DEBUG || - [JobExecutionService] ForkJoinPool.commonPool-worker-3 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Execution of job '0be4-2460-45c0-0001', execution 0be4-2460-45c0-0001 completed with failure java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:332) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:347) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:874) ~[?:?] at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[?:?] at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2162) ~[?:?] at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:72) ~[classes/:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:502) ~[classes/:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:433) ~[classes/:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:419) ~[classes/:?] at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:807) ~[?:?] at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:373) ~[classes/:?] at java.base/java.lang.Thread.run(Thread.java:857) ~[?:?] Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:318) ~[classes/:?] at com.hazelcast.jet.impl.JobExecutionService.terminateExecution0(JobExecutionService.java:726) ~[classes/:?] at com.hazelcast.jet.impl.JobExecutionService.terminateExecution(JobExecutionService.java:722) ~[classes/:?] at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.doRun(TerminateExecutionOperation.java:59) ~[classes/:?] at com.hazelcast.jet.impl.operation.AsyncOperation.run(AsyncOperation.java:55) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:193) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:294) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:265) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.run(OperationExecutorImpl.java:459) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.runOrExecute(OperationExecutorImpl.java:519) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:618) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:597) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:558) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:241) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:71) ~[classes/:?] at com.hazelcast.jet.impl.LightMasterContext.cancelInvocations(LightMasterContext.java:269) ~[classes/:?] at com.hazelcast.jet.impl.LightMasterContext.requestTermination(LightMasterContext.java:365) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.terminateLightJob(JobCoordinationService.java:522) ~[classes/:?] at com.hazelcast.jet.impl.operation.TerminateJobOperation.doRun(TerminateJobOperation.java:52) ~[classes/:?] at com.hazelcast.jet.impl.operation.AsyncOperation.run(AsyncOperation.java:55) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:193) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:294) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:265) ~[classes/:?] at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:497) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:185) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:141) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.loop(OperationThread.java:134) ~[classes/:?] at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.executeRun(OperationThread.java:115) ~[classes/:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111) ~[classes/:?] 10:55:17,812 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-6 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] null com.hazelcast.jet.core.JobNotFoundException: Job with id 0be4-2460-45c0-0001 not found at com.hazelcast.jet.impl.JobCoordinationService.lambda$callWithJob$52(JobCoordinationService.java:1078) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.submitToCoordinatorThread(JobCoordinationService.java:1490) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.callWithJob(JobCoordinationService.java:1030) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$getJobIds$20(JobCoordinationService.java:543) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$submitToCoordinatorThread$61(JobCoordinationService.java:1502) ~[classes/:?] at com.hazelcast.internal.util.executor.CompletableFutureTask.run(CompletableFutureTask.java:64) [classes/:?] at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate$Worker.run(CachedExecutorServiceDelegate.java:220) [classes/:?] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.base/java.lang.Thread.run(Thread.java:857) [?:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76) [classes/:?] at com.hazelcast.internal.util.executor.PoolExecutorThreadFactory$ManagedThread.executeRun(PoolExecutorThreadFactory.java:74) [classes/:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111) [classes/:?] 10:55:17,812 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] null com.hazelcast.jet.core.JobNotFoundException: Job with id 0be4-2460-45c0-0001 not found at com.hazelcast.jet.impl.JobCoordinationService.lambda$callWithJob$52(JobCoordinationService.java:1078) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.submitToCoordinatorThread(JobCoordinationService.java:1490) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.callWithJob(JobCoordinationService.java:1030) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$getJobIds$20(JobCoordinationService.java:543) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$submitToCoordinatorThread$61(JobCoordinationService.java:1502) ~[classes/:?] at com.hazelcast.internal.util.executor.CompletableFutureTask.run(CompletableFutureTask.java:64) [classes/:?] at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate$Worker.run(CachedExecutorServiceDelegate.java:220) [classes/:?] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.base/java.lang.Thread.run(Thread.java:857) [?:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76) [classes/:?] at com.hazelcast.internal.util.executor.PoolExecutorThreadFactory$ManagedThread.executeRun(PoolExecutorThreadFactory.java:74) [classes/:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111) [classes/:?] 10:55:17,813 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] null com.hazelcast.jet.core.JobNotFoundException: Job with id 0be4-2460-45c0-0001 not found at com.hazelcast.jet.impl.JobCoordinationService.lambda$callWithJob$52(JobCoordinationService.java:1078) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.submitToCoordinatorThread(JobCoordinationService.java:1490) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.callWithJob(JobCoordinationService.java:1030) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$getJobIds$20(JobCoordinationService.java:543) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$submitToCoordinatorThread$61(JobCoordinationService.java:1502) ~[classes/:?] at com.hazelcast.internal.util.executor.CompletableFutureTask.run(CompletableFutureTask.java:64) [classes/:?] at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate$Worker.run(CachedExecutorServiceDelegate.java:220) [classes/:?] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.base/java.lang.Thread.run(Thread.java:857) [?:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76) [classes/:?] at com.hazelcast.internal.util.executor.PoolExecutorThreadFactory$ManagedThread.executeRun(PoolExecutorThreadFactory.java:74) [classes/:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111) [classes/:?] 10:55:17,813 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JobCoordinationService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-3 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] null com.hazelcast.jet.core.JobNotFoundException: Job with id 0be4-2460-45c0-0001 not found at com.hazelcast.jet.impl.JobCoordinationService.lambda$callWithJob$52(JobCoordinationService.java:1078) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.submitToCoordinatorThread(JobCoordinationService.java:1490) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.callWithJob(JobCoordinationService.java:1030) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$getJobIds$20(JobCoordinationService.java:543) ~[classes/:?] at com.hazelcast.jet.impl.JobCoordinationService.lambda$submitToCoordinatorThread$61(JobCoordinationService.java:1502) ~[classes/:?] at com.hazelcast.internal.util.executor.CompletableFutureTask.run(CompletableFutureTask.java:64) [classes/:?] at com.hazelcast.internal.util.executor.CachedExecutorServiceDelegate$Worker.run(CachedExecutorServiceDelegate.java:220) [classes/:?] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.base/java.lang.Thread.run(Thread.java:857) [?:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76) [classes/:?] at com.hazelcast.internal.util.executor.PoolExecutorThreadFactory$ManagedThread.executeRun(PoolExecutorThreadFactory.java:74) [classes/:?] at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:111) [classes/:?] 10:55:17,815 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [JetTestSupport] Time-limited test - Terminating instanceFactory in JetTestSupport.@After 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] HazelcastClient 5.4.1-SNAPSHOT (20240622) is SHUTTING_DOWN 10:55:17,816 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [TestClientRegistry$MockedServerConnection] pool-13317-thread-1 - Server connection closed: null 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MockServer] pool-13317-thread-1 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Removed connection to endpoint: [address=[127.0.0.1]:40001, uuid=9c9800b8-d788-47de-8085-c16ec6c9f2fa], connection: MockedNodeConnection{ remoteAddress = [127.0.0.1]:40001, localAddress = [127.0.0.1]:5702, connectionId = 1} 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientConnectionManager] Thread-40224 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Removed connection to endpoint: [127.0.0.1]:5702:734825c3-0817-48ae-ba4a-27c90d755cd9, connection: MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=false, connectionId=1, channel=null, remoteAddress=[127.0.0.1]:5702, lastReadTime=2024-06-22 10:55:17.784, lastWriteTime=2024-06-22 10:55:17.784, closedTime=2024-06-22 10:55:17.816}} 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientConnectionManager] Thread-40224 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] Removed connection to endpoint: [127.0.0.1]:5701:48e087a8-2915-45ae-837d-b7d5b6320d96, connection: MockedClientConnection{localAddress=[127.0.0.1]:40002, super=ClientConnection{alive=false, connectionId=2, channel=null, remoteAddress=[127.0.0.1]:5701, lastReadTime=2024-06-22 10:55:17.781, lastWriteTime=2024-06-22 10:55:17.780, closedTime=2024-06-22 10:55:17.816}} 10:55:17,816 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [TwoWayBlockableExecutor] pool-13317-thread-1 - Dropping incoming runnable since other end closed. Server Closed EOF. MockedClientConnection{localAddress=[127.0.0.1]:40001, super=ClientConnection{alive=false, connectionId=1, channel=null, remoteAddress=[127.0.0.1]:5702, lastReadTime=2024-06-22 10:55:17.784, lastWriteTime=2024-06-22 10:55:17.784, closedTime=2024-06-22 10:55:17.816}} 10:55:17,816 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [TestClientRegistry$MockedServerConnection] pool-13319-thread-1 - Server connection closed: null 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] HazelcastClient 5.4.1-SNAPSHOT (20240622) is CLIENT_DISCONNECTED 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MockServer] pool-13319-thread-1 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Removed connection to endpoint: [address=[127.0.0.1]:40002, uuid=9c9800b8-d788-47de-8085-c16ec6c9f2fa], connection: MockedNodeConnection{ remoteAddress = [127.0.0.1]:40002, localAddress = [127.0.0.1]:5701, connectionId = 2} 10:55:17,816 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientEndpointManager] hz.JobSummaryTest_elastic_goldwasser.event-46237 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Destroying ClientEndpoint{connection=MockedNodeConnection{ remoteAddress = [127.0.0.1]:40001, localAddress = [127.0.0.1]:5702, connectionId = 1}, clientUuid=9c9800b8-d788-47de-8085-c16ec6c9f2fa, clientName=hz.client_4464, authenticated=true, clientVersion=5.4.1-SNAPSHOT, creationTime=1719053717774, latest clientAttributes=lastStatisticsCollectionTime=1719053717781,enterprise=false,clientType=JVM,clientVersion=5.4.1-SNAPSHOT,clusterConnectionTimestamp=1719053717774,clientAddress=127.0.0.1,clientName=hz.client_4464,credentials.principal=null,os.committedVirtualMemorySize=48286351360,os.freePhysicalMemorySize=158047055872,os.freeSwapSpaceSize=8246988800,os.maxFileDescriptorCount=1048576,os.openFileDescriptorCount=388,os.processCpuTime=2858355252000,os.systemLoadAverage=1.15869140625,os.totalPhysicalMemorySize=405593460736,os.totalSwapSpaceSize=8589930496,runtime.availableProcessors=8,runtime.freeMemory=7751127984,runtime.maxMemory=8589934592,runtime.totalMemory=8589934592,runtime.uptime=2956084,runtime.usedMemory=838806608, labels=[]} 10:55:17,816 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [TwoWayBlockableExecutor] pool-13319-thread-1 - Dropping incoming runnable since other end closed. Server Closed EOF. MockedClientConnection{localAddress=[127.0.0.1]:40002, super=ClientConnection{alive=false, connectionId=2, channel=null, remoteAddress=[127.0.0.1]:5701, lastReadTime=2024-06-22 10:55:17.781, lastWriteTime=2024-06-22 10:55:17.780, closedTime=2024-06-22 10:55:17.816}} 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - hz.client_4464 [dev] [5.4.1-SNAPSHOT] HazelcastClient 5.4.1-SNAPSHOT (20240622) is SHUTDOWN 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5702 is SHUTTING_DOWN 10:55:17,817 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Terminating forcefully... 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Shutting down connection manager... 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MockServer] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Removed connection to endpoint: [address=[127.0.0.1]:5702, uuid=734825c3-0817-48ae-ba4a-27c90d755cd9], connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5701, uuid=48e087a8-2915-45ae-837d-b7d5b6320d96], remoteEndpoint=[address=[127.0.0.1]:5702, uuid=734825c3-0817-48ae-ba4a-27c90d755cd9], alive=false} 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MockServer] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Removed connection to endpoint: [address=[127.0.0.1]:5701, uuid=48e087a8-2915-45ae-837d-b7d5b6320d96], connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5702, uuid=734825c3-0817-48ae-ba4a-27c90d755cd9], remoteEndpoint=[address=[127.0.0.1]:5701, uuid=48e087a8-2915-45ae-837d-b7d5b6320d96], alive=false} 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MembershipManager] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Removing Member [127.0.0.1]:5702 - 734825c3-0817-48ae-ba4a-27c90d755cd9 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [PartitionStateManager] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Storing snapshot of partition assignments while removing UUID 734825c3-0817-48ae-ba4a-27c90d755cd9 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClientEndpointManager] hz.JobSummaryTest_stoic_goldwasser.event-46236 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Destroying ClientEndpoint{connection=MockedNodeConnection{ remoteAddress = [127.0.0.1]:40002, localAddress = [127.0.0.1]:5701, connectionId = 2}, clientUuid=9c9800b8-d788-47de-8085-c16ec6c9f2fa, clientName=hz.client_4464, authenticated=true, clientVersion=5.4.1-SNAPSHOT, creationTime=1719053717777, latest clientAttributes=null, labels=[]} 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [ClusterService] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Members {size:1, ver:3} [ Member [127.0.0.1]:5701 - 48e087a8-2915-45ae-837d-b7d5b6320d96 this ] 10:55:17,817 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [TransactionManagerService] hz.JobSummaryTest_stoic_goldwasser.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 734825c3-0817-48ae-ba4a-27c90d755cd9 10:55:17,818 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Shutting down node engine... 10:55:17,819 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [MigrationManager] hz.JobSummaryTest_stoic_goldwasser.migration - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Partition balance is ok, no need to repartition. 10:55:17,820 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [NodeExtension] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Destroying node NodeExtension. 10:55:17,820 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] Hazelcast Shutdown is completed in 3 ms. 10:55:17,820 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - [127.0.0.1]:5702 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5702 is SHUTDOWN 10:55:17,820 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5701 is SHUTTING_DOWN 10:55:17,820 WARN |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Terminating forcefully... 10:55:17,820 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Shutting down connection manager... 10:55:17,820 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Shutting down node engine... 10:55:17,822 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [NodeExtension] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Destroying node NodeExtension. 10:55:17,822 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [Node] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] Hazelcast Shutdown is completed in 2 ms. 10:55:17,822 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [LifecycleService] Thread-40224 - [127.0.0.1]:5701 [dev] [5.4.1-SNAPSHOT] [127.0.0.1]:5701 is SHUTDOWN 10:55:17,822 INFO |when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true]| - [HazelcastTestSupport] Time-limited test - Shutting down node factory as @After action BuildInfo right after when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true](com.hazelcast.jet.impl.JobSummaryTest): BuildInfo{version='5.4.1-SNAPSHOT', build='20240622', buildNumber=20240622, revision=, enterprise=false, serializationVersion=1} Hiccups measured while running test 'when_manyJobs_then_sortedBySubmissionTime[useOldJobSummary=true](com.hazelcast.jet.impl.JobSummaryTest):' 10:55:15, accumulated pauses: 36 ms, max pause: 7 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-5.maintenance-Openj9-17/124/