Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode fails due to execution not being terminated #26328

Open
AleksPeychev opened this issue May 7, 2024 · 1 comment
Open

com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode fails due to execution not being terminated #26328

AleksPeychev opened this issue May 7, 2024 · 1 comment
Labels
Module: Jet Issues/PRs for Jet Source: Internal PR or issue was opened by an employee Team: Integration Type: Test-Failure
Milestone
5.5.0

Comments

@AleksPeychev
Copy link
Contributor

master (commit 064036486c8da3725b2659995598618715f31904)
Failed on Windows - OracleJDK21: https://jenkins.hazelcast.com/view/Official%20Builds/job/Hazelcast-master-Windows-OracleJDK21/2/testReport/junit/com.hazelcast.jet.core/CancellationTest/when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode_useLightJob_false_/

Stacktrace: 
java.lang.AssertionError: Call counter should eventually stop being incremented.
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.assertTrue(Assert.java:42)
	at com.hazelcast.jet.core.CancellationTest.lambda$assertExecutionTerminated$4(CancellationTest.java:390)
	at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1210)
	at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1229)
	at com.hazelcast.jet.core.CancellationTest.assertExecutionTerminated(CancellationTest.java:386)
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:266)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
	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:317)
	at java.base/java.lang.Thread.run(Thread.java:1583)
Standard output: 
Finished Running Test: when_cancellingCompletedJob_then_succeeds[useLightJob=false] in 0.034 seconds.
Started Running Test: when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]
19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MetricsConfigHelper] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [LOCAL] [dev] [5.5.0-SNAPSHOT] Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [logo] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-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

19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Copyright (c) 2008-2024, Hazelcast, Inc. All Rights Reserved.
19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Hazelcast Platform 5.5.0-SNAPSHOT (20240506) starting at [127.0.0.1]:5701
19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Cluster name: dev
19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Integrity Checker is disabled. Fail-fast on corrupted executables will not be performed. For more information, see the documentation for Integrity Checker.
19:16:45,811  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Jet is enabled
19:16:45,815  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MetricsConfigHelper] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled
19:16:45,822  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JetServiceBackend] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Setting number of cooperative threads and default parallelism to 2
19:16:45,823  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Diagnostics] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
19:16:45,823  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5701 is STARTING
19:16:45,823  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [ClusterService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] 

Members {size:1, ver:1} [
	Member [127.0.0.1]:5701 - 05f1f39c-7a61-41b1-acab-417b78b721e9 this
]

19:16:45,823  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobCoordinationService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Jet started scanning for jobs
19:16:45,823  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5701 is STARTED
19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MetricsConfigHelper] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [LOCAL] [dev] [5.5.0-SNAPSHOT] Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [logo] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-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

19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Copyright (c) 2008-2024, Hazelcast, Inc. All Rights Reserved.
19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Hazelcast Platform 5.5.0-SNAPSHOT (20240506) starting at [127.0.0.1]:5702
19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Cluster name: dev
19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Integrity Checker is disabled. Fail-fast on corrupted executables will not be performed. For more information, see the documentation for Integrity Checker.
19:16:45,824  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [system] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Jet is enabled
19:16:45,826 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobCoordinationService] hz.CancellationTest_crazy_babbage.cached.thread-6 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
19:16:45,827  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MetricsConfigHelper] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled
19:16:45,834  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JetServiceBackend] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Setting number of cooperative threads and default parallelism to 2
19:16:45,835  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Diagnostics] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
19:16:45,835  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5702 is STARTING
19:16:45,835  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MockServer] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Created connection to endpoint: [127.0.0.1]:5701-05f1f39c-7a61-41b1-acab-417b78b721e9, connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5702, uuid=9516c3d3-6b88-4c5b-8222-3026abbcc506], remoteEndpoint=[address=[127.0.0.1]:5701, uuid=05f1f39c-7a61-41b1-acab-417b78b721e9], alive=true}
19:16:45,836  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MockServer] hz.CancellationTest_crazy_babbage.priority-generic-operation.thread-0 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Created connection to endpoint: [127.0.0.1]:5702-9516c3d3-6b88-4c5b-8222-3026abbcc506, connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5701, uuid=05f1f39c-7a61-41b1-acab-417b78b721e9], remoteEndpoint=[address=[127.0.0.1]:5702, uuid=9516c3d3-6b88-4c5b-8222-3026abbcc506], alive=true}
19:16:45,836  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [ClusterService] hz.CancellationTest_crazy_babbage.priority-generic-operation.thread-0 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] 

Members {size:2, ver:2} [
	Member [127.0.0.1]:5701 - 05f1f39c-7a61-41b1-acab-417b78b721e9 this
	Member [127.0.0.1]:5702 - 9516c3d3-6b88-4c5b-8222-3026abbcc506
]

19:16:45,927 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobCoordinationService] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
19:16:45,936  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [ClusterService] hz.CancellationTest_compassionate_babbage.priority-generic-operation.thread-0 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] 

Members {size:2, ver:2} [
	Member [127.0.0.1]:5701 - 05f1f39c-7a61-41b1-acab-417b78b721e9
	Member [127.0.0.1]:5702 - 9516c3d3-6b88-4c5b-8222-3026abbcc506 this
]

19:16:45,937  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobCoordinationService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Jet started scanning for jobs
19:16:45,937  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5702 is STARTED
19:16:45,938  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [PartitionStateManagerImpl] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Initializing cluster partition table arrangement...
19:16:45,938 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobClassLoaderService] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Creating job classLoader for job 0ba8-146e-3c40-0001
19:16:45,938 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobClassLoaderService] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Create processor classloader map for job 0ba8-146e-3c40-0001
19:16:45,940  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobCoordinationService] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Starting job 0ba8-146e-3c40-0001 based on submit request
19:16:45,943  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Didn't find any snapshot to restore for job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001
19:16:45,943  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Start executing job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001, execution graph in DOT format:
digraph DAG {
	"faulty" [localParallelism=4];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
19:16:45,943 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Building execution plan for job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001
19:16:45,943 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Built execution plans for job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001
19:16:45,943 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [InitExecutionOperation] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Initializing execution plan for job 0ba8-146e-3c40-0001, execution 0ba8-146e-3c41-0001 from [127.0.0.1]:5701
19:16:45,944  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobExecutionService] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Execution plan for jobId=0ba8-146e-3c40-0001, jobName='0ba8-146e-3c40-0001', executionId=0ba8-146e-3c41-0001 initialized
19:16:45,945 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [InitExecutionOperation] hz.CancellationTest_compassionate_babbage.generic-operation.thread-1 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Initializing execution plan for job 0ba8-146e-3c40-0001, execution 0ba8-146e-3c41-0001 from [127.0.0.1]:5701
19:16:45,945 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobClassLoaderService] hz.CancellationTest_compassionate_babbage.generic-operation.thread-1 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Creating job classLoader for job 0ba8-146e-3c40-0001
19:16:45,945 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobClassLoaderService] hz.CancellationTest_compassionate_babbage.generic-operation.thread-1 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Create processor classloader map for job 0ba8-146e-3c40-0001
19:16:45,945  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobExecutionService] hz.CancellationTest_compassionate_babbage.generic-operation.thread-1 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Execution plan for jobId=0ba8-146e-3c40-0001, jobName='0ba8-146e-3c40-0001', executionId=0ba8-146e-3c41-0001 initialized
19:16:45,946 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Init of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 was successful
19:16:45,946 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Executing job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001
19:16:45,946  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobExecutionService] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Start execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 from coordinator [127.0.0.1]:5701
19:16:45,946  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobExecutionService] hz.CancellationTest_compassionate_babbage.generic-operation.thread-0 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Start execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 from coordinator [127.0.0.1]:5701
19:16:46,031 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobRepository] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Job cleanup took 0ms
19:16:46,142  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TaskletExecutionService] hz.CancellationTest_compassionate_babbage.jet.cooperative.thread-1 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#4}
java.lang.RuntimeException: fault
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:254) ~[test-classes/:?]
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.13.2.jar:4.13.2]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) ~[test-classes/:?]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) ~[test-classes/:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
19:16:46,142  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TaskletExecutionService] hz.CancellationTest_compassionate_babbage.jet.cooperative.thread-0 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}
java.lang.RuntimeException: fault
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:254) ~[test-classes/:?]
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.13.2.jar:4.13.2]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) ~[test-classes/:?]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) ~[test-classes/:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
19:16:55,838 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterContext] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Not scaling up job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001: not running or already running on all members
19:17:05,502  WARN |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TaskletExecutionService] hz.CancellationTest_compassionate_babbage.jet.cooperative.thread-0 - Logging took 19357 ms.
19:17:05,502  WARN |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterContext] hz.CancellationTest_crazy_babbage.cached.thread-4 - Logging took 9662 ms.
19:17:05,502  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TaskletExecutionService] hz.CancellationTest_compassionate_babbage.jet.cooperative.thread-0 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#7}
java.lang.RuntimeException: fault
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:254) ~[test-classes/:?]
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.13.2.jar:4.13.2]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) ~[test-classes/:?]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) ~[test-classes/:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
19:16:51,033 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobRepository] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Job cleanup took 0ms
19:17:05,502  WARN |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobRepository] hz.CancellationTest_crazy_babbage.cached.thread-7 - Logging took 14467 ms.
19:17:05,502  WARN |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TaskletExecutionService] hz.CancellationTest_compassionate_babbage.jet.cooperative.thread-1 - Logging took 19358 ms.
19:17:05,504  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TaskletExecutionService] hz.CancellationTest_compassionate_babbage.jet.cooperative.thread-1 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#6}
java.lang.RuntimeException: fault
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:254) ~[test-classes/:?]
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.13.2.jar:4.13.2]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) ~[test-classes/:?]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) ~[test-classes/:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
19:17:06,014 DEBUG || - [JobClassLoaderService] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Finish JobClassLoaders phaseCount = 0, removing classloaders for jobId=0ba8-146e-3c40-0001
19:17:06,017 DEBUG || - [JobExecutionService] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Completed execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001
19:17:06,017 DEBUG || - [JobExecutionService] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.JetException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault
	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:2194) ~[?:?]
	at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:72) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:501) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:432) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:418) ~[classes/:?]
	at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:372) ~[classes/:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) ~[?:?]
Caused by: com.hazelcast.jet.JetException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault
	at com.hazelcast.jet.impl.execution.TaskletExecutionService.handleTaskletExecutionError(TaskletExecutionService.java:289) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:413) ~[classes/:?]
	... 3 more
Caused by: com.hazelcast.jet.impl.execution.TaskletExecutionException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault
	at com.hazelcast.jet.impl.execution.TaskletExecutionService.handleTaskletExecutionError(TaskletExecutionService.java:288) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:413) ~[classes/:?]
	... 3 more
Caused by: java.lang.RuntimeException: fault
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:254) ~[test-classes/:?]
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.13.2.jar:4.13.2]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) ~[test-classes/:?]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) ~[test-classes/:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	... 1 more
19:17:06,018 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 received response to StartExecutionOperation from [127.0.0.1]:5702: com.hazelcast.jet.JetException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault
19:17:06,023 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobRepository] hz.CancellationTest_crazy_babbage.cached.thread-7 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Job cleanup took 0ms
19:17:06,023 DEBUG || - [JobExecutionService] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Completed execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001
19:17:06,023 DEBUG || - [JobExecutionService] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 was cancelled
19:17:06,023  WARN || - [StartExecutionOperation] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] null
com.hazelcast.jet.impl.execution.ExecutionCancellationException: null
	at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:315) ~[classes/:?]
	at com.hazelcast.jet.impl.JobExecutionService.terminateExecution0(JobExecutionService.java:724) ~[classes/:?]
	at com.hazelcast.jet.impl.JobExecutionService.terminateExecution(JobExecutionService.java:720) ~[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:192) ~[classes/:?]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:291) ~[classes/:?]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:262) ~[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:617) ~[classes/:?]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:596) ~[classes/:?]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:557) ~[classes/:?]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:240) ~[classes/:?]
	at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:71) ~[classes/:?]
	at com.hazelcast.jet.impl.MasterContext.invokeOnParticipant(MasterContext.java:479) ~[classes/:?]
	at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:462) ~[classes/:?]
	at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:433) ~[classes/:?]
	at com.hazelcast.jet.impl.MasterJobContext.lambda$cancelExecutionInvocations$24(MasterJobContext.java:779) ~[classes/:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) ~[?:?]
	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/:?]
Caused by: java.util.concurrent.CancellationException
	at com.hazelcast.jet.impl.JobExecutionService.terminateExecution(JobExecutionService.java:719) ~[classes/:?]
	... 23 more
19:17:06,023 DEBUG || - [MasterJobContext] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 received response to StartExecutionOperation from [127.0.0.1]:5701: com.hazelcast.jet.impl.execution.ExecutionCancellationException
19:17:06,023 DEBUG || - [MasterJobContext] ForkJoinPool.commonPool-worker-15 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 has failures: [[127.0.0.1]:5701=com.hazelcast.jet.impl.execution.ExecutionCancellationException, [127.0.0.1]:5702=com.hazelcast.jet.JetException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault]
19:17:06,024 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobClassLoaderService] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Finish JobClassLoaders phaseCount = 0, removing classloaders for jobId=0ba8-146e-3c40-0001
19:17:06,024 ERROR |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MasterJobContext] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Execution of job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 failed
	Start time: 2024-05-06T19:16:45.940
	Duration: 00:00:20.084
	To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
com.hazelcast.jet.JetException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault
	at com.hazelcast.jet.impl.execution.TaskletExecutionService.handleTaskletExecutionError(TaskletExecutionService.java:289) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:413) ~[classes/:?]
	at java.base/java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:372) ~[classes/:?]
	at java.base/java.lang.Thread.run(Thread.java:1583) ~[?:?]
Caused by: com.hazelcast.jet.impl.execution.TaskletExecutionException: Exception in ProcessorTasklet{0ba8-146e-3c40-0001/faulty#5}: java.lang.RuntimeException: fault
	at com.hazelcast.jet.impl.execution.TaskletExecutionService.handleTaskletExecutionError(TaskletExecutionService.java:288) ~[classes/:?]
	... 4 more
Caused by: java.lang.RuntimeException: fault
	at com.hazelcast.jet.core.CancellationTest.when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode(CancellationTest.java:254) ~[test-classes/:?]
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[?:?]
	at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[?:?]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56) ~[junit-4.13.2.jar:4.13.2]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[junit-4.13.2.jar:4.13.2]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:115) ~[test-classes/:?]
	at com.hazelcast.test.FailOnTimeoutStatement$CallableStatement.call(FailOnTimeoutStatement.java:107) ~[test-classes/:?]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
	... 1 more
19:17:06,025 DEBUG |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JobCoordinationService] hz.CancellationTest_crazy_babbage.cached.thread-4 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] job '0ba8-146e-3c40-0001', execution 0ba8-146e-3c41-0001 is completed
19:17:06,029  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [JetTestSupport] Time-limited test - Terminating instanceFactory in JetTestSupport.@After
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5702 is SHUTTING_DOWN
19:17:06,030  WARN |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Terminating forcefully...
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Shutting down connection manager...
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MockServer] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Removed connection to endpoint: [address=[127.0.0.1]:5702, uuid=9516c3d3-6b88-4c5b-8222-3026abbcc506], connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5701, uuid=05f1f39c-7a61-41b1-acab-417b78b721e9], remoteEndpoint=[address=[127.0.0.1]:5702, uuid=9516c3d3-6b88-4c5b-8222-3026abbcc506], alive=false}
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MockServer] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Removed connection to endpoint: [address=[127.0.0.1]:5701, uuid=05f1f39c-7a61-41b1-acab-417b78b721e9], connection: MockConnection{localEndpoint=[address=[127.0.0.1]:5702, uuid=9516c3d3-6b88-4c5b-8222-3026abbcc506], remoteEndpoint=[address=[127.0.0.1]:5701, uuid=05f1f39c-7a61-41b1-acab-417b78b721e9], alive=false}
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MembershipManager] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Removing Member [127.0.0.1]:5702 - 9516c3d3-6b88-4c5b-8222-3026abbcc506
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [PartitionStateManagerImpl] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Storing snapshot of partition assignments while removing UUID 9516c3d3-6b88-4c5b-8222-3026abbcc506
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [ClusterService] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] 

Members {size:1, ver:3} [
	Member [127.0.0.1]:5701 - 05f1f39c-7a61-41b1-acab-417b78b721e9 this
]

19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Shutting down node engine...
19:17:06,030  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [TransactionManagerService] hz.CancellationTest_crazy_babbage.cached.thread-9 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 9516c3d3-6b88-4c5b-8222-3026abbcc506
19:17:06,031  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [MigrationManagerImpl] hz.CancellationTest_crazy_babbage.migration - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Partition balance is ok, no need to repartition.
19:17:06,038  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [NodeExtension] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Destroying node NodeExtension.
19:17:06,040  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] Hazelcast Shutdown is completed in 10 ms.
19:17:06,040  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] Thread-49234 - [127.0.0.1]:5702 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5702 is SHUTDOWN
19:17:06,040  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5701 is SHUTTING_DOWN
19:17:06,040  WARN |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Terminating forcefully...
19:17:06,040  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Shutting down connection manager...
19:17:06,040  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Shutting down node engine...
19:17:06,047  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [NodeExtension] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Destroying node NodeExtension.
19:17:06,047  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [Node] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] Hazelcast Shutdown is completed in 7 ms.
19:17:06,047  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [LifecycleService] Thread-49234 - [127.0.0.1]:5701 [dev] [5.5.0-SNAPSHOT] [127.0.0.1]:5701 is SHUTDOWN
19:17:06,047  INFO |when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false]| - [HazelcastTestSupport] Time-limited test - Shutting down node factory as @After action
BuildInfo right after when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false](com.hazelcast.jet.core.CancellationTest): BuildInfo{version='5.5.0-SNAPSHOT', build='20240506', buildNumber=20240506, revision=, enterprise=false, serializationVersion=1}
Hiccups measured while running test 'when_jobFailsOnNonInitiatorNode_then_cancelledOnInitiatorNode[useLightJob=false](com.hazelcast.jet.core.CancellationTest):'
19:16:45, accumulated pauses: 731 ms, max pause: 4 ms, pauses over 1000 ms: 0
19:16:50, accumulated pauses: 732 ms, max pause: 2 ms, pauses over 1000 ms: 0
19:16:55, accumulated pauses: 733 ms, max pause: 2 ms, pauses over 1000 ms: 0
19:17:00, accumulated pauses: 738 ms, max pause: 15 ms, pauses over 1000 ms: 0
19:17:05, accumulated pauses: 585 ms, max pause: 506 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-Windows-OracleJDK21/2/
@AleksPeychev AleksPeychev added Team: Core Type: Test-Failure Source: Internal PR or issue was opened by an employee Module: Jet Issues/PRs for Jet labels May 7, 2024
@AleksPeychev AleksPeychev added this to the 5.5.0 milestone May 7, 2024
@AleksPeychev AleksPeychev added Team: Integration Source: Internal PR or issue was opened by an employee and removed Team: Core Source: Internal PR or issue was opened by an employee labels May 7, 2024
@sumnerib
Copy link
Contributor

Failed again on master with Windows - MicrosoftJDK17: https://jenkins.hazelcast.com/job/Hazelcast-master-Windows-MicrosoftJDK17/115/testReport/com.hazelcast.jet.core/CancellationTest/when_jobFailsOnInitiatorNode_then_cancelledOnOtherNodes_useLightJob_false_/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Module: Jet Issues/PRs for Jet Source: Internal PR or issue was opened by an employee Team: Integration Type: Test-Failure
Projects
None yet
Milestone
5.5.0
Development

No branches or pull requests
2 participants
@sumnerib @AleksPeychev