You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
java.lang.AssertionError: the size of the collection is not correct: found-content:[message-0, message-1, message-2, message-3, message-4, message-5, message-6, message-7, message-8, message-9, message-0, message-1, message-2, message-3, message-4, message-5, message-6, message-7, message-8, message-9] expected:<10> but was:<20>
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at com.hazelcast.test.HazelcastTestSupport$6.run(HazelcastTestSupport.java:1092)
at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1356)
at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1373)
at com.hazelcast.test.HazelcastTestSupport.assertSizeEventually(HazelcastTestSupport.java:1089)
at com.hazelcast.test.HazelcastTestSupport.assertSizeEventually(HazelcastTestSupport.java:1085)
at com.hazelcast.jet.contrib.http.HttpListenerSinkTest.lambda$testWebsocket_when_portConfigured$6(HttpListenerSinkTest.java:256)
at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1356)
at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1458)
at com.hazelcast.jet.contrib.http.HttpListenerSinkTest.testWebsocket_when_portConfigured(HttpListenerSinkTest.java:256)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:239)
at com.hazelcast.test.DumpBuildInfoOnFailureRule$1.evaluate(DumpBuildInfoOnFailureRule.java:37)
at com.hazelcast.test.jitter.JitterRule$1.evaluate(JitterRule.java:104)
at com.hazelcast.test.metrics.MetricsRule$1.evaluate(MetricsRule.java:62)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.lang.Thread.run(Thread.java:748)
Standard output:
14:53:02,976 INFO || - [JetConfig] Time-limited test - jet.home is /home/jenkins/jenkins_slave/workspace/jet-contrib-tests/http
14:53:03,100 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:53:03,164 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5701
14:53:03,164 INFO || - [system] Time-limited test - Cluster name: jet
14:53:03,164 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:53:03,164 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:53:03,422 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:53:03,443 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:53:03,805 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:53:04,167 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:53:04,168 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:53:04,246 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:53:04,250 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:53:04,258 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:53:04,271 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTING
14:53:04,284 INFO || - [ClusterService] Time-limited test -
Members {size:1, ver:1} [
Member [127.0.0.1]:5701 - 26b93e06-dfb3-4bc6-baeb-0a199c0f1c4d this
]
14:53:04,297 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-2 - Not starting jobs because partitions are not yet initialized.
14:53:04,299 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTED
14:53:04,397 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-2 - Not starting jobs because partitions are not yet initialized.
14:53:04,498 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-2 - Not starting jobs because partitions are not yet initialized.
14:53:04,598 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-2 - Not starting jobs because partitions are not yet initialized.
14:53:04,609 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast7243711257415144720jks, length: 1371
14:53:04,612 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast3133384594850428381jks, length: 665
14:53:04,614 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:53:04,615 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5702
14:53:04,615 INFO || - [system] Time-limited test - Cluster name: jet
14:53:04,616 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:53:04,616 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:53:04,620 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:53:04,620 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:53:04,629 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:53:04,636 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:53:04,636 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:53:04,647 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:53:04,648 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:53:04,658 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:53:04,659 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTING
14:53:04,662 INFO || - [MockNetworkingService] Time-limited test - Created connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=true}
14:53:04,676 INFO || - [MockNetworkingService] hz.sleepy_cohen.priority-generic-operation.thread-0 - Created connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=true}
14:53:04,679 INFO || - [ClusterService] hz.sleepy_cohen.generic-operation.thread-1 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - 26b93e06-dfb3-4bc6-baeb-0a199c0f1c4d this
Member [127.0.0.1]:5702 - cc1a1e1c-d504-4bcc-873d-0c762d102d9c
]
14:53:04,692 INFO || - [ClusterService] hz.admiring_cohen.priority-generic-operation.thread-0 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - 26b93e06-dfb3-4bc6-baeb-0a199c0f1c4d
Member [127.0.0.1]:5702 - cc1a1e1c-d504-4bcc-873d-0c762d102d9c this
]
14:53:04,698 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:04,799 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:04,899 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:04,999 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:05,100 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:05,171 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTED
14:53:05,200 INFO || - [xnio] Time-limited test - XNIO version 3.8.0.Final
14:53:05,200 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-2 - Not starting jobs because partitions are not yet initialized.
14:53:05,217 INFO || - [nio] Time-limited test - XNIO NIO Implementation Version 3.8.0.Final
14:53:05,258 INFO || - [threads] Time-limited test - JBoss Threads version 3.1.0.Final
14:53:05,344 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:05,416 INFO || - [PartitionStateManager] hz.sleepy_cohen.cached.thread-4 - Initializing cluster partition table arrangement...
14:53:05,561 DEBUG || - [Planner] hz.sleepy_cohen.cached.thread-4 - Watermarks in the pipeline will be throttled to 1000
14:53:05,599 DEBUG || - [JobRepository] hz.sleepy_cohen.cached.thread-3 - Job cleanup took 18ms
14:53:05,624 INFO || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-4 - Starting job 0568-d17e-7c40-0001 based on submit request
14:53:05,669 INFO || - [MasterJobContext] hz.sleepy_cohen.cached.thread-4 - Didn't find any snapshot to restore for job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:05,669 INFO || - [MasterJobContext] hz.sleepy_cohen.cached.thread-4 - Start executing job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001, execution graph in DOT format:
digraph DAG {
"b1547a8b-ca95-489c-87dc-3ba4dbbd2e1e" [localParallelism=1];
"websocket:8081" [localParallelism=1];
"b1547a8b-ca95-489c-87dc-3ba4dbbd2e1e" -> "websocket:8081" [label="distributed-partitioned", queueSize=1024];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
14:53:05,670 DEBUG || - [MasterJobContext] hz.sleepy_cohen.cached.thread-4 - Building execution plan for job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:05,684 DEBUG || - [MasterJobContext] hz.sleepy_cohen.cached.thread-4 - Built execution plans for job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:05,688 DEBUG || - [InitExecutionOperation] hz.admiring_cohen.generic-operation.thread-10 - Initializing execution plan for job 0568-d17e-7c40-0001, execution 0568-d17e-7c41-0001 from [127.0.0.1]:5701
14:53:05,691 DEBUG || - [InitExecutionOperation] hz.sleepy_cohen.cached.thread-4 - Initializing execution plan for job 0568-d17e-7c40-0001, execution 0568-d17e-7c41-0001 from [127.0.0.1]:5701
14:53:05,774 INFO || - [JobExecutionService] hz.admiring_cohen.generic-operation.thread-10 - Execution plan for jobId=0568-d17e-7c40-0001, jobName='0568-d17e-7c40-0001', executionId=0568-d17e-7c41-0001 initialized
14:53:05,774 INFO || - [JobExecutionService] hz.sleepy_cohen.cached.thread-4 - Execution plan for jobId=0568-d17e-7c40-0001, jobName='0568-d17e-7c40-0001', executionId=0568-d17e-7c41-0001 initialized
14:53:05,776 DEBUG || - [MasterJobContext] hz.sleepy_cohen.cached.thread-4 - Init of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 was successful
14:53:05,776 DEBUG || - [MasterJobContext] hz.sleepy_cohen.cached.thread-4 - Executing job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:05,778 INFO || - [JobExecutionService] hz.sleepy_cohen.cached.thread-4 - Start execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 from coordinator [127.0.0.1]:5701
14:53:05,778 INFO || - [JobExecutionService] hz.admiring_cohen.generic-operation.thread-11 - Start execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 from coordinator [127.0.0.1]:5701
14:53:05,802 WARN || - [TestKeyStoreUtil] hz.sleepy_cohen.jet.blocking.thread-0 - Keystore file path: /tmp/hazelcast4917963098537404529jks, length: 1371
14:53:05,804 WARN || - [TestKeyStoreUtil] hz.sleepy_cohen.jet.blocking.thread-0 - Keystore file path: /tmp/hazelcast8938912757866516456jks, length: 665
14:53:05,836 INFO || - [undertow] hz.sleepy_cohen.jet.blocking.thread-0 - starting server: Undertow - 2.1.1.Final
14:53:05,960 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast2543570211218329597jks, length: 1371
14:53:05,961 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast617082313082908460jks, length: 665
14:53:06,462 DEBUG || - [Job] Time-limited test - Sending CANCEL_FORCEFUL request for job 0568-d17e-7c40-0001 (name ??)
14:53:06,472 DEBUG || - [JobExecutionService] hz.sleepy_cohen.jet.cooperative.thread-4 - Execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:392)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:378)
at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:346)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.run(OperationExecutorImpl.java:406)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.runOrExecute(OperationExecutorImpl.java:433)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:596)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:581)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:540)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:237)
at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:59)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipant(MasterContext.java:261)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:245)
at com.hazelcast.jet.impl.MasterJobContext.lambda$cancelExecutionInvocations$16(MasterJobContext.java:597)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:64)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:80)
14:53:06,472 DEBUG || - [JobExecutionService] hz.admiring_cohen.jet.cooperative.thread-2 - Execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:392)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:378)
at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:346)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:422)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:166)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:136)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:123)
14:53:06,485 DEBUG || - [MasterJobContext] ForkJoinPool.commonPool-worker-105 - job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 to be cancelled after Execution
14:53:06,486 DEBUG || - [MasterJobContext] hz.sleepy_cohen.cached.thread-6 - Sending CompleteExecutionOperation for job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:06,492 DEBUG || - [CompleteExecutionOperation] hz.sleepy_cohen.cached.thread-6 - Completing execution 0568-d17e-7c41-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:53:06,494 DEBUG || - [CompleteExecutionOperation] hz.admiring_cohen.generic-operation.thread-13 - Completing execution 0568-d17e-7c41-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:53:06,495 DEBUG || - [JobExecutionService] hz.admiring_cohen.generic-operation.thread-13 - Completed execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:06,496 INFO || - [undertow] hz.sleepy_cohen.cached.thread-6 - stopping server: Undertow - 2.1.1.Final
14:53:06,499 DEBUG || - [JobExecutionService] hz.sleepy_cohen.cached.thread-6 - Completed execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001
14:53:06,508 INFO || - [MasterJobContext] hz.sleepy_cohen.cached.thread-6 - Execution of job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 got terminated, reason=java.util.concurrent.CancellationException
Start time: 2020-12-11T14:53:05.625
Duration: 876 ms
To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
14:53:06,515 DEBUG || - [JobCoordinationService] hz.sleepy_cohen.cached.thread-6 - job '0568-d17e-7c40-0001', execution 0568-d17e-7c41-0001 is completed
14:53:06,667 INFO || - [JetTestSupport] Time-limited test - Terminating instanceFactory in JetTestSupport.@After
14:53:06,668 INFO || - [LifecycleService] Thread-6 - [127.0.0.1]:5702 is SHUTTING_DOWN
14:53:06,673 WARN || - [Node] Thread-6 - Terminating forcefully...
14:53:06,673 INFO || - [Node] Thread-6 - Shutting down connection manager...
14:53:06,673 INFO || - [MockNetworkingService] Thread-6 - Removed connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=false}
14:53:06,674 INFO || - [MockNetworkingService] Thread-6 - Removed connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=false}
14:53:06,674 INFO || - [MembershipManager] Thread-6 - Removing Member [127.0.0.1]:5702 - cc1a1e1c-d504-4bcc-873d-0c762d102d9c
14:53:06,676 INFO || - [ClusterService] Thread-6 -
Members {size:1, ver:3} [
Member [127.0.0.1]:5701 - 26b93e06-dfb3-4bc6-baeb-0a199c0f1c4d this
]
14:53:06,676 INFO || - [Node] Thread-6 - Shutting down node engine...
14:53:06,677 INFO || - [TransactionManagerService] hz.sleepy_cohen.cached.thread-4 - Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: cc1a1e1c-d504-4bcc-873d-0c762d102d9c
14:53:06,707 INFO || - [NodeExtension] Thread-6 - Destroying node NodeExtension.
14:53:06,707 INFO || - [Node] Thread-6 - Hazelcast Shutdown is completed in 34 ms.
14:53:06,707 INFO || - [LifecycleService] Thread-6 - [127.0.0.1]:5702 is SHUTDOWN
14:53:06,707 INFO || - [LifecycleService] Thread-6 - [127.0.0.1]:5701 is SHUTTING_DOWN
14:53:06,709 WARN || - [Node] Thread-6 - Terminating forcefully...
14:53:06,709 INFO || - [Node] Thread-6 - Shutting down connection manager...
14:53:06,709 INFO || - [Node] Thread-6 - Shutting down node engine...
14:53:06,731 INFO || - [NodeExtension] Thread-6 - Destroying node NodeExtension.
14:53:06,731 INFO || - [Node] Thread-6 - Hazelcast Shutdown is completed in 22 ms.
14:53:06,731 INFO || - [LifecycleService] Thread-6 - [127.0.0.1]:5701 is SHUTDOWN
14:53:06,734 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:53:06,735 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5701
14:53:06,735 INFO || - [system] Time-limited test - Cluster name: jet
14:53:06,735 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:53:06,735 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:53:06,738 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:53:06,738 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:53:06,746 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:53:06,754 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:53:06,754 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:53:06,762 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:53:06,763 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:53:06,770 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:53:06,770 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTING
14:53:06,771 INFO || - [ClusterService] Time-limited test -
Members {size:1, ver:1} [
Member [127.0.0.1]:5701 - cab69443-6dcc-4c41-96b4-076f176630d2 this
]
14:53:06,771 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-1 - Not starting jobs because partitions are not yet initialized.
14:53:06,771 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTED
14:53:06,773 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast317891110437798613jks, length: 1371
14:53:06,774 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast1189811977365889495jks, length: 665
14:53:06,778 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:53:06,779 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5702
14:53:06,779 INFO || - [system] Time-limited test - Cluster name: jet
14:53:06,779 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:53:06,780 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:53:06,785 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:53:06,785 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:53:06,791 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:53:06,799 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:53:06,800 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:53:06,808 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:53:06,809 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:53:06,817 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:53:06,818 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTING
14:53:06,818 INFO || - [MockNetworkingService] Time-limited test - Created connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=true}
14:53:06,824 INFO || - [MockNetworkingService] hz.adoring_cohen.generic-operation.thread-1 - Created connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=true}
14:53:06,826 INFO || - [ClusterService] hz.adoring_cohen.generic-operation.thread-1 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - cab69443-6dcc-4c41-96b4-076f176630d2 this
Member [127.0.0.1]:5702 - 38c10e76-ff65-439a-b902-a570dd7bee24
]
14:53:06,828 INFO || - [ClusterService] hz.infallible_cohen.priority-generic-operation.thread-0 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - cab69443-6dcc-4c41-96b4-076f176630d2
Member [127.0.0.1]:5702 - 38c10e76-ff65-439a-b902-a570dd7bee24 this
]
14:53:06,872 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:06,972 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:07,072 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:07,172 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:07,272 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-4 - Not starting jobs because partitions are not yet initialized.
14:53:07,323 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTED
14:53:07,336 INFO || - [PartitionStateManager] hz.adoring_cohen.cached.thread-4 - Initializing cluster partition table arrangement...
14:53:07,346 DEBUG || - [Planner] hz.adoring_cohen.cached.thread-4 - Watermarks in the pipeline will be throttled to 1000
14:53:07,353 INFO || - [JobCoordinationService] hz.adoring_cohen.cached.thread-4 - Starting job 0568-d180-6000-0001 based on submit request
14:53:07,393 INFO || - [MasterJobContext] hz.adoring_cohen.cached.thread-4 - Didn't find any snapshot to restore for job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:07,394 INFO || - [MasterJobContext] hz.adoring_cohen.cached.thread-4 - Start executing job '0568-d180-6000-0001', execution 0568-d180-6001-0001, execution graph in DOT format:
digraph DAG {
"ed4e78a0-b4a0-4ddf-935d-9cf4dd899027" [localParallelism=1];
"serverSent:8081" [localParallelism=1];
"ed4e78a0-b4a0-4ddf-935d-9cf4dd899027" -> "serverSent:8081" [label="distributed-partitioned", queueSize=1024];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
14:53:07,394 DEBUG || - [MasterJobContext] hz.adoring_cohen.cached.thread-4 - Building execution plan for job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:07,396 DEBUG || - [MasterJobContext] hz.adoring_cohen.cached.thread-4 - Built execution plans for job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:07,398 DEBUG || - [InitExecutionOperation] hz.infallible_cohen.generic-operation.thread-7 - Initializing execution plan for job 0568-d180-6000-0001, execution 0568-d180-6001-0001 from [127.0.0.1]:5701
14:53:07,400 DEBUG || - [InitExecutionOperation] hz.adoring_cohen.cached.thread-4 - Initializing execution plan for job 0568-d180-6000-0001, execution 0568-d180-6001-0001 from [127.0.0.1]:5701
14:53:07,417 INFO || - [JobExecutionService] hz.infallible_cohen.generic-operation.thread-7 - Execution plan for jobId=0568-d180-6000-0001, jobName='0568-d180-6000-0001', executionId=0568-d180-6001-0001 initialized
14:53:07,418 INFO || - [JobExecutionService] hz.adoring_cohen.cached.thread-4 - Execution plan for jobId=0568-d180-6000-0001, jobName='0568-d180-6000-0001', executionId=0568-d180-6001-0001 initialized
14:53:07,423 DEBUG || - [MasterJobContext] hz.adoring_cohen.cached.thread-4 - Init of job '0568-d180-6000-0001', execution 0568-d180-6001-0001 was successful
14:53:07,423 DEBUG || - [MasterJobContext] hz.adoring_cohen.cached.thread-4 - Executing job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:07,423 INFO || - [JobExecutionService] hz.adoring_cohen.cached.thread-4 - Start execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001 from coordinator [127.0.0.1]:5701
14:53:07,430 INFO || - [JobExecutionService] hz.infallible_cohen.generic-operation.thread-11 - Start execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001 from coordinator [127.0.0.1]:5701
14:53:07,435 DEBUG || - [JobRepository] hz.adoring_cohen.cached.thread-1 - Job cleanup took 19ms
14:53:07,439 WARN || - [TestKeyStoreUtil] hz.adoring_cohen.jet.blocking.thread-0 - Keystore file path: /tmp/hazelcast2424568953032052698jks, length: 1371
14:53:07,440 WARN || - [TestKeyStoreUtil] hz.adoring_cohen.jet.blocking.thread-0 - Keystore file path: /tmp/hazelcast4428992423416692859jks, length: 665
14:53:07,441 INFO || - [undertow] hz.adoring_cohen.jet.blocking.thread-0 - starting server: Undertow - 2.1.1.Final
14:53:07,768 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast7931220182370934699jks, length: 1371
14:53:07,769 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast6283238787945682784jks, length: 665
14:53:07,769 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast6126947594669464752jks, length: 665
14:53:07,850 DEBUG || - [EventSource] Time-limited test - readyState change: RAW -> CONNECTING
14:53:07,851 INFO || - [EventSource] Time-limited test - Starting EventSource client using URI: https://0.0.0.0:8081/
14:53:07,855 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - readyState change: CONNECTING -> CONNECTING
14:53:08,019 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - readyState change: CONNECTING -> OPEN
14:53:08,020 INFO || - [EventSource] okhttp-eventsource-stream-[]-0 - Connected to Event Source stream.
14:53:08,059 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-0
14:53:08,059 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,060 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-1
14:53:08,060 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,060 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-2
14:53:08,060 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-3
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-4
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-5
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-6
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-7
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,061 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-8
14:53:08,062 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,062 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-9
14:53:08,062 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:53:08,260 DEBUG || - [Job] Time-limited test - Sending CANCEL_FORCEFUL request for job 0568-d180-6000-0001 (name ??)
14:53:08,264 DEBUG || - [JobExecutionService] hz.infallible_cohen.jet.blocking.thread-0 - Execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:309)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:422)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:166)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:136)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:123)
14:53:08,270 DEBUG || - [JobExecutionService] hz.adoring_cohen.jet.blocking.thread-0 - Execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:309)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.run(OperationExecutorImpl.java:406)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.runOrExecute(OperationExecutorImpl.java:433)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:596)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:581)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:540)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:237)
at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:59)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipant(MasterContext.java:261)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:245)
at com.hazelcast.jet.impl.MasterJobContext.lambda$cancelExecutionInvocations$16(MasterJobContext.java:597)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:64)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:80)
14:53:08,271 DEBUG || - [MasterJobContext] ForkJoinPool.commonPool-worker-4 - job '0568-d180-6000-0001', execution 0568-d180-6001-0001 to be cancelled after Execution
14:53:08,271 DEBUG || - [MasterJobContext] hz.adoring_cohen.cached.thread-5 - Sending CompleteExecutionOperation for job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:08,274 DEBUG || - [CompleteExecutionOperation] hz.adoring_cohen.cached.thread-5 - Completing execution 0568-d180-6001-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:53:08,275 INFO || - [undertow] hz.adoring_cohen.cached.thread-5 - stopping server: Undertow - 2.1.1.Final
14:53:08,279 DEBUG || - [CompleteExecutionOperation] hz.infallible_cohen.generic-operation.thread-13 - Completing execution 0568-d180-6001-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:53:08,280 DEBUG || - [JobExecutionService] hz.infallible_cohen.generic-operation.thread-13 - Completed execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:08,287 WARN || - [EventSource] okhttp-eventsource-stream-[]-0 - Connection unexpectedly closed.
14:53:08,288 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - readyState change: OPEN -> CLOSED
14:53:08,288 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - response closed
14:53:08,288 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - buffered source closed
14:53:08,290 INFO || - [EventSource] okhttp-eventsource-stream-[]-0 - Waiting 1970 milliseconds before reconnecting...
14:53:08,290 DEBUG || - [JobExecutionService] hz.adoring_cohen.cached.thread-5 - Completed execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001
14:53:08,290 INFO || - [MasterJobContext] hz.adoring_cohen.cached.thread-5 - Execution of job '0568-d180-6000-0001', execution 0568-d180-6001-0001 got terminated, reason=java.util.concurrent.CancellationException
Start time: 2020-12-11T14:53:07.353
Duration: 937 ms
To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
14:53:08,292 DEBUG || - [JobCoordinationService] hz.adoring_cohen.cached.thread-5 - job '0568-d180-6000-0001', execution 0568-d180-6001-0001 is completed
14:53:08,464 DEBUG || - [EventSource] Time-limited test - readyState change: CLOSED -> SHUTDOWN
14:53:08,465 DEBUG || - [EventSource] Time-limited test - call cancelled
14:53:08,467 INFO || - [JetTestSupport] Time-limited test - Terminating instanceFactory in JetTestSupport.@After
14:53:08,467 INFO || - [LifecycleService] Thread-7 - [127.0.0.1]:5702 is SHUTTING_DOWN
14:53:08,470 WARN || - [Node] Thread-7 - Terminating forcefully...
14:53:08,470 INFO || - [Node] Thread-7 - Shutting down connection manager...
14:53:08,471 INFO || - [MockNetworkingService] Thread-7 - Removed connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=false}
14:53:08,471 INFO || - [MockNetworkingService] Thread-7 - Removed connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=false}
14:53:08,471 INFO || - [MembershipManager] Thread-7 - Removing Member [127.0.0.1]:5702 - 38c10e76-ff65-439a-b902-a570dd7bee24
14:53:08,472 INFO || - [TransactionManagerService] hz.adoring_cohen.cached.thread-5 - Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 38c10e76-ff65-439a-b902-a570dd7bee24
14:53:08,472 INFO || - [ClusterService] Thread-7 -
Members {size:1, ver:3} [
Member [127.0.0.1]:5701 - cab69443-6dcc-4c41-96b4-076f176630d2 this
]
14:53:08,474 INFO || - [Node] Thread-7 - Shutting down node engine...
14:53:08,558 INFO || - [NodeExtension] Thread-7 - Destroying node NodeExtension.
14:53:08,587 INFO || - [Node] Thread-7 - Hazelcast Shutdown is completed in 117 ms.
14:53:08,588 INFO || - [LifecycleService] Thread-7 - [127.0.0.1]:5702 is SHUTDOWN
14:53:08,588 INFO || - [LifecycleService] Thread-7 - [127.0.0.1]:5701 is SHUTTING_DOWN
14:53:08,590 WARN || - [Node] Thread-7 - Terminating forcefully...
14:53:08,590 INFO || - [Node] Thread-7 - Shutting down connection manager...
14:53:08,593 INFO || - [Node] Thread-7 - Shutting down node engine...
14:53:08,748 INFO || - [NodeExtension] Thread-7 - Destroying node NodeExtension.
14:53:08,749 INFO || - [Node] Thread-7 - Hazelcast Shutdown is completed in 160 ms.
14:53:08,749 INFO || - [LifecycleService] Thread-7 - [127.0.0.1]:5701 is SHUTDOWN
14:53:08,751 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:53:08,752 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5701
14:53:08,752 INFO || - [system] Time-limited test - Cluster name: jet
14:53:08,752 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:53:08,752 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:53:08,755 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:53:08,756 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:53:08,761 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:53:08,767 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:53:08,768 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:53:08,775 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:53:08,775 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:53:08,782 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:53:08,782 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTING
14:53:08,783 INFO || - [ClusterService] Time-limited test -
Members {size:1, ver:1} [
Member [127.0.0.1]:5701 - 7a1df9a6-fcd1-45b3-98eb-2458746552e8 this
]
14:53:08,783 DEBUG || - [JobCoordinationService] hz.reverent_cohen.cached.thread-1 - Not starting jobs because partitions are not yet initialized.
14:53:08,783 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTED
14:53:08,785 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast130359515128363259jks, length: 1371
14:53:08,786 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast4195303905811583463jks, length: 665
14:53:08,787 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:53:08,788 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5702
14:53:08,788 INFO || - [system] Time-limited test - Cluster name: jet
14:53:08,788 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:53:08,789 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:53:08,792 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:53:08,793 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:53:08,799 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide stro
...[truncated 279628 chars]...
mitOperation] hz.modest_cohen.priority-generic-operation.thread-0 - Promotion of 135 partitions failed. . Promotion partition state version: 1084, current partition state version: 814
14:55:29,272 WARN || - [Invocation] hz.modest_cohen.priority-generic-operation.thread-0 - Future.complete(Object) on completed future. Request: Invocation{op=com.hazelcast.internal.partition.operation.PromotionCommitOperation{serviceName='hz:core:partitionService', identityHash=1249127368, partitionId=-1, replicaIndex=0, callId=-27294, invocationTime=1607698529254 (2020-12-11 14:55:29.254), waitTimeout=-1, callTimeout=60000}, tryCount=2147483647, tryPauseMillis=500, invokeCount=1, callTimeoutMillis=60000, firstInvocationTimeMs=1607698529254, firstInvocationTime='2020-12-11 14:55:29.254', lastHeartbeatMillis=0, lastHeartbeatTime='1970-01-01 00:00:00.000', target=[127.0.0.1]:5701, pendingResponse={VOID}, backupsAcksExpected=-1, backupsAcksReceived=0, connection=null}, current value: ExceptionalResult{cause=com.hazelcast.core.HazelcastInstanceNotActiveException: Hazelcast instance is not active!}, offered value: false
java.lang.Exception
at com.hazelcast.spi.impl.AbstractInvocationFuture.warnIfSuspiciousDoubleCompletion(AbstractInvocationFuture.java:1218)
at com.hazelcast.spi.impl.AbstractInvocationFuture.complete0(AbstractInvocationFuture.java:1195)
at com.hazelcast.spi.impl.AbstractInvocationFuture.complete(AbstractInvocationFuture.java:1184)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.complete(Invocation.java:652)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.sendResponse(Invocation.java:232)
at com.hazelcast.spi.impl.operationservice.Operation.sendResponse(Operation.java:470)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:237)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:160)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:138)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:123)
14:55:29,274 INFO || - [NodeExtension] Thread-20 - Destroying node NodeExtension.
14:55:29,275 INFO || - [Node] Thread-20 - Hazelcast Shutdown is completed in 16 ms.
14:55:29,275 INFO || - [LifecycleService] Thread-20 - [127.0.0.1]:5701 is SHUTDOWN
BuildInfo right after testWebsocket_when_portConfigured(com.hazelcast.jet.contrib.http.HttpListenerSinkTest): BuildInfo{version='4.0.3', build='20200921', buildNumber=20200921, revision=59ae831, enterprise=false, serializationVersion=1, jet=JetBuildInfo{version='4.3', build='20201020', revision='a47fbc5'}}
Hiccups measured while running test 'testWebsocket_when_portConfigured(com.hazelcast.jet.contrib.http.HttpListenerSinkTest):'
14:53:25, accumulated pauses: 55 ms, max pause: 21 ms, pauses over 1000 ms: 0
14:53:30, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:53:35, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:53:40, accumulated pauses: 27 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:53:45, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:53:50, accumulated pauses: 39 ms, max pause: 12 ms, pauses over 1000 ms: 0
14:53:55, accumulated pauses: 27 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:00, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:05, accumulated pauses: 28 ms, max pause: 2 ms, pauses over 1000 ms: 0
14:54:10, accumulated pauses: 27 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:15, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:20, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:25, accumulated pauses: 29 ms, max pause: 1 ms, pauses over 1000 ms: 0
14:54:30, accumulated pauses: 56 ms, max pause: 25 ms, pauses over 1000 ms: 0
14:54:35, accumulated pauses: 54 ms, max pause: 10 ms, pauses over 1000 ms: 0
14:54:40, accumulated pauses: 28 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:45, accumulated pauses: 29 ms, max pause: 0 ms, pauses over 1000 ms: 0
14:54:50, accumulated pauses: 34 ms, max pause: 3 ms, pauses over 1000 ms: 0
14:54:55, accumulated pauses: 32 ms, max pause: 1 ms, pauses over 1000 ms: 0
14:55:00, accumulated pauses: 29 ms, max pause: 1 ms, pauses over 1000 ms: 0
14:55:05, accumulated pauses: 37 ms, max pause: 3 ms, pauses over 1000 ms: 0
14:55:10, accumulated pauses: 31 ms, max pause: 1 ms, pauses over 1000 ms: 0
14:55:15, accumulated pauses: 30 ms, max pause: 1 ms, pauses over 1000 ms: 0
14:55:20, accumulated pauses: 44 ms, max pause: 18 ms, pauses over 1000 ms: 0
14:55:25, accumulated pauses: 25 ms, max pause: 2 ms, pauses over 1000 ms: 0
No metrics recorded during the test
14:55:29,284 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:55:29,286 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5701
14:55:29,286 INFO || - [system] Time-limited test - Cluster name: jet
14:55:29,286 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:55:29,286 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:55:29,289 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:55:29,289 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:55:29,295 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:55:29,299 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:55:29,299 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:55:29,304 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:55:29,304 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:55:29,310 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:55:29,310 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTING
14:55:29,310 INFO || - [ClusterService] Time-limited test -
Members {size:1, ver:1} [
Member [127.0.0.1]:5701 - b1086d21-ac09-4b09-932b-77964fcbfeab this
]
14:55:29,311 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-1 - Not starting jobs because partitions are not yet initialized.
14:55:29,311 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTED
14:55:29,313 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast8394029412737691609jks, length: 1371
14:55:29,314 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast1441888922730745119jks, length: 665
14:55:29,316 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:55:29,317 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5702
14:55:29,317 INFO || - [system] Time-limited test - Cluster name: jet
14:55:29,317 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:55:29,317 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:55:29,320 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:55:29,320 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:55:29,326 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:55:29,330 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:55:29,330 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:55:29,336 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:55:29,336 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:55:29,342 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:55:29,342 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTING
14:55:29,343 INFO || - [MockNetworkingService] Time-limited test - Created connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=true}
14:55:29,343 INFO || - [MockNetworkingService] hz.kind_cohen.priority-generic-operation.thread-0 - Created connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=true}
14:55:29,344 INFO || - [ClusterService] hz.kind_cohen.generic-operation.thread-1 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - b1086d21-ac09-4b09-932b-77964fcbfeab this
Member [127.0.0.1]:5702 - 4728efe1-32d7-4127-b3de-e32d7f5606da
]
14:55:29,344 INFO || - [ClusterService] hz.unruffled_cohen.priority-generic-operation.thread-0 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - b1086d21-ac09-4b09-932b-77964fcbfeab
Member [127.0.0.1]:5702 - 4728efe1-32d7-4127-b3de-e32d7f5606da this
]
14:55:29,411 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:29,511 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:29,611 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:29,712 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:29,812 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-2 - Not starting jobs because partitions are not yet initialized.
14:55:29,844 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTED
14:55:29,847 INFO || - [PartitionStateManager] hz.kind_cohen.cached.thread-2 - Initializing cluster partition table arrangement...
14:55:29,851 DEBUG || - [Planner] hz.kind_cohen.cached.thread-2 - Watermarks in the pipeline will be throttled to 1000
14:55:29,853 INFO || - [JobCoordinationService] hz.kind_cohen.cached.thread-2 - Starting job 0568-d20b-8d80-0001 based on submit request
14:55:29,858 INFO || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Didn't find any snapshot to restore for job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:29,858 INFO || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Start executing job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001, execution graph in DOT format:
digraph DAG {
"7f55ecef-af30-450f-9845-da487c4f0bab" [localParallelism=1];
"websocket:8081" [localParallelism=1];
"7f55ecef-af30-450f-9845-da487c4f0bab" -> "websocket:8081" [label="distributed-partitioned", queueSize=1024];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
14:55:29,858 DEBUG || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Building execution plan for job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:29,859 DEBUG || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Built execution plans for job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:29,860 DEBUG || - [InitExecutionOperation] hz.unruffled_cohen.generic-operation.thread-7 - Initializing execution plan for job 0568-d20b-8d80-0001, execution 0568-d20b-8d81-0001 from [127.0.0.1]:5701
14:55:29,861 DEBUG || - [InitExecutionOperation] hz.kind_cohen.cached.thread-2 - Initializing execution plan for job 0568-d20b-8d80-0001, execution 0568-d20b-8d81-0001 from [127.0.0.1]:5701
14:55:29,869 INFO || - [JobExecutionService] hz.unruffled_cohen.generic-operation.thread-7 - Execution plan for jobId=0568-d20b-8d80-0001, jobName='0568-d20b-8d80-0001', executionId=0568-d20b-8d81-0001 initialized
14:55:29,869 INFO || - [JobExecutionService] hz.kind_cohen.cached.thread-2 - Execution plan for jobId=0568-d20b-8d80-0001, jobName='0568-d20b-8d80-0001', executionId=0568-d20b-8d81-0001 initialized
14:55:29,869 DEBUG || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Init of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 was successful
14:55:29,869 DEBUG || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Executing job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:29,869 INFO || - [JobExecutionService] hz.kind_cohen.cached.thread-2 - Start execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 from coordinator [127.0.0.1]:5701
14:55:29,869 INFO || - [JobExecutionService] hz.unruffled_cohen.generic-operation.thread-8 - Start execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 from coordinator [127.0.0.1]:5701
14:55:29,873 INFO || - [undertow] hz.unruffled_cohen.jet.blocking.thread-0 - starting server: Undertow - 2.1.1.Final
14:55:29,920 DEBUG || - [JobRepository] hz.kind_cohen.cached.thread-2 - Job cleanup took 2ms
14:55:30,269 DEBUG || - [Job] Time-limited test - Sending CANCEL_FORCEFUL request for job 0568-d20b-8d80-0001 (name ??)
14:55:30,272 DEBUG || - [JobExecutionService] hz.kind_cohen.jet.blocking.thread-0 - Execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:309)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.run(OperationExecutorImpl.java:406)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.runOrExecute(OperationExecutorImpl.java:433)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:596)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:581)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:540)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:237)
at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:59)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipant(MasterContext.java:261)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:245)
at com.hazelcast.jet.impl.MasterJobContext.lambda$cancelExecutionInvocations$16(MasterJobContext.java:597)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:64)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:80)
14:55:30,276 DEBUG || - [JobExecutionService] hz.unruffled_cohen.jet.blocking.thread-0 - Execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:309)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:422)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:166)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:136)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:123)
14:55:30,278 DEBUG || - [MasterJobContext] ForkJoinPool.commonPool-worker-106 - job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 to be cancelled after Execution
14:55:30,278 DEBUG || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Sending CompleteExecutionOperation for job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:30,279 DEBUG || - [CompleteExecutionOperation] hz.kind_cohen.cached.thread-2 - Completing execution 0568-d20b-8d81-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:55:30,279 DEBUG || - [JobExecutionService] hz.kind_cohen.cached.thread-2 - Completed execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:30,279 DEBUG || - [CompleteExecutionOperation] hz.unruffled_cohen.generic-operation.thread-13 - Completing execution 0568-d20b-8d81-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:55:30,280 INFO || - [undertow] hz.unruffled_cohen.generic-operation.thread-13 - stopping server: Undertow - 2.1.1.Final
14:55:30,283 DEBUG || - [JobExecutionService] hz.unruffled_cohen.generic-operation.thread-13 - Completed execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001
14:55:30,283 INFO || - [MasterJobContext] hz.kind_cohen.cached.thread-2 - Execution of job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 got terminated, reason=java.util.concurrent.CancellationException
Start time: 2020-12-11T14:55:29.853
Duration: 430 ms
To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
14:55:30,284 DEBUG || - [JobCoordinationService] hz.kind_cohen.cached.thread-2 - job '0568-d20b-8d80-0001', execution 0568-d20b-8d81-0001 is completed
14:55:30,470 INFO || - [JetTestSupport] Time-limited test - Terminating instanceFactory in JetTestSupport.@After
14:55:30,471 INFO || - [LifecycleService] Thread-21 - [127.0.0.1]:5702 is SHUTTING_DOWN
14:55:30,472 WARN || - [Node] Thread-21 - Terminating forcefully...
14:55:30,472 INFO || - [Node] Thread-21 - Shutting down connection manager...
14:55:30,473 INFO || - [MockNetworkingService] Thread-21 - Removed connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=false}
14:55:30,473 INFO || - [MockNetworkingService] Thread-21 - Removed connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=false}
14:55:30,473 INFO || - [MembershipManager] Thread-21 - Removing Member [127.0.0.1]:5702 - 4728efe1-32d7-4127-b3de-e32d7f5606da
14:55:30,474 INFO || - [ClusterService] Thread-21 -
Members {size:1, ver:3} [
Member [127.0.0.1]:5701 - b1086d21-ac09-4b09-932b-77964fcbfeab this
]
14:55:30,474 INFO || - [TransactionManagerService] hz.kind_cohen.cached.thread-2 - Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 4728efe1-32d7-4127-b3de-e32d7f5606da
14:55:30,475 INFO || - [Node] Thread-21 - Shutting down node engine...
14:55:30,487 INFO || - [NodeExtension] Thread-21 - Destroying node NodeExtension.
14:55:30,488 INFO || - [Node] Thread-21 - Hazelcast Shutdown is completed in 16 ms.
14:55:30,488 INFO || - [LifecycleService] Thread-21 - [127.0.0.1]:5702 is SHUTDOWN
14:55:30,488 INFO || - [LifecycleService] Thread-21 - [127.0.0.1]:5701 is SHUTTING_DOWN
14:55:30,489 WARN || - [Node] Thread-21 - Terminating forcefully...
14:55:30,489 INFO || - [Node] Thread-21 - Shutting down connection manager...
14:55:30,490 INFO || - [Node] Thread-21 - Shutting down node engine...
14:55:30,499 INFO || - [NodeExtension] Thread-21 - Destroying node NodeExtension.
14:55:30,500 INFO || - [Node] Thread-21 - Hazelcast Shutdown is completed in 11 ms.
14:55:30,500 INFO || - [LifecycleService] Thread-21 - [127.0.0.1]:5701 is SHUTDOWN
14:55:30,501 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:55:30,502 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5701
14:55:30,502 INFO || - [system] Time-limited test - Cluster name: jet
14:55:30,502 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:55:30,502 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:55:30,506 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:55:30,506 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:55:30,509 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:55:30,512 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:55:30,512 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:55:30,517 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:55:30,517 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:55:30,522 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:55:30,523 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTING
14:55:30,523 INFO || - [ClusterService] Time-limited test -
Members {size:1, ver:1} [
Member [127.0.0.1]:5701 - 71e8cd3c-d856-40a2-8aea-5c48e48f31cf this
]
14:55:30,523 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5701 is STARTED
14:55:30,523 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-1 - Not starting jobs because partitions are not yet initialized.
14:55:30,524 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast3088425273372121020jks, length: 1371
14:55:30,525 WARN || - [TestKeyStoreUtil] Time-limited test - Keystore file path: /tmp/hazelcast1063430569244057471jks, length: 665
14:55:30,526 INFO || - [MetricsConfigHelper] Time-limited test - Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
14:55:30,527 INFO || - [system] Time-limited test - Hazelcast Jet 4.3 (20201020 - a47fbc5) starting at [127.0.0.1]:5702
14:55:30,527 INFO || - [system] Time-limited test - Cluster name: jet
14:55:30,527 INFO || - [system] Time-limited test -
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---o o---o o---o o---o o o o---o o o--o o---o o
14:55:30,527 INFO || - [system] Time-limited test - Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
14:55:30,529 INFO || - [MetricsConfigHelper] Time-limited test - Collecting debug metrics and sending to diagnostics is enabled
14:55:30,529 INFO || - [BackpressureRegulator] Time-limited test - Backpressure is disabled
14:55:30,533 WARN || - [CPSubsystem] Time-limited test - CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
14:55:30,536 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
14:55:30,536 INFO || - [TaskletExecutionService] Time-limited test - Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
14:55:30,541 INFO || - [JetService] Time-limited test - Setting number of cooperative threads and default parallelism to 72
14:55:30,541 INFO || - [OperationExecutorImpl] Time-limited test - Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
14:55:30,546 INFO || - [Diagnostics] Time-limited test - Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
14:55:30,546 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTING
14:55:30,546 INFO || - [MockNetworkingService] Time-limited test - Created connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=true}
14:55:30,547 INFO || - [MockNetworkingService] hz.cocky_cohen.priority-generic-operation.thread-0 - Created connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=true}
14:55:30,547 INFO || - [ClusterService] hz.cocky_cohen.generic-operation.thread-1 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - 71e8cd3c-d856-40a2-8aea-5c48e48f31cf this
Member [127.0.0.1]:5702 - 554463d5-6b5f-421f-9b52-67436107ffa4
]
14:55:30,548 INFO || - [ClusterService] hz.romantic_cohen.generic-operation.thread-3 -
Members {size:2, ver:2} [
Member [127.0.0.1]:5701 - 71e8cd3c-d856-40a2-8aea-5c48e48f31cf
Member [127.0.0.1]:5702 - 554463d5-6b5f-421f-9b52-67436107ffa4 this
]
14:55:30,624 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:30,724 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:30,824 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:30,925 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-6 - Not starting jobs because partitions are not yet initialized.
14:55:31,025 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-3 - Not starting jobs because partitions are not yet initialized.
14:55:31,047 INFO || - [LifecycleService] Time-limited test - [127.0.0.1]:5702 is STARTED
14:55:31,050 INFO || - [PartitionStateManager] hz.cocky_cohen.cached.thread-3 - Initializing cluster partition table arrangement...
14:55:31,053 DEBUG || - [Planner] hz.cocky_cohen.cached.thread-3 - Watermarks in the pipeline will be throttled to 1000
14:55:31,055 INFO || - [JobCoordinationService] hz.cocky_cohen.cached.thread-3 - Starting job 0568-d20c-ba40-0001 based on submit request
14:55:31,061 INFO || - [MasterJobContext] hz.cocky_cohen.cached.thread-3 - Didn't find any snapshot to restore for job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,061 INFO || - [MasterJobContext] hz.cocky_cohen.cached.thread-3 - Start executing job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001, execution graph in DOT format:
digraph DAG {
"b509e044-bcc5-4bcd-8cee-c61d15c474f4" [localParallelism=1];
"serverSent:8081" [localParallelism=1];
"b509e044-bcc5-4bcd-8cee-c61d15c474f4" -> "serverSent:8081" [label="distributed-partitioned", queueSize=1024];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
14:55:31,061 DEBUG || - [MasterJobContext] hz.cocky_cohen.cached.thread-3 - Building execution plan for job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,061 DEBUG || - [MasterJobContext] hz.cocky_cohen.cached.thread-3 - Built execution plans for job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,062 DEBUG || - [InitExecutionOperation] hz.romantic_cohen.generic-operation.thread-7 - Initializing execution plan for job 0568-d20c-ba40-0001, execution 0568-d20c-ba41-0001 from [127.0.0.1]:5701
14:55:31,062 DEBUG || - [InitExecutionOperation] hz.cocky_cohen.cached.thread-3 - Initializing execution plan for job 0568-d20c-ba40-0001, execution 0568-d20c-ba41-0001 from [127.0.0.1]:5701
14:55:31,068 INFO || - [JobExecutionService] hz.cocky_cohen.cached.thread-3 - Execution plan for jobId=0568-d20c-ba40-0001, jobName='0568-d20c-ba40-0001', executionId=0568-d20c-ba41-0001 initialized
14:55:31,068 INFO || - [JobExecutionService] hz.romantic_cohen.generic-operation.thread-7 - Execution plan for jobId=0568-d20c-ba40-0001, jobName='0568-d20c-ba40-0001', executionId=0568-d20c-ba41-0001 initialized
14:55:31,068 DEBUG || - [MasterJobContext] hz.cocky_cohen.cached.thread-3 - Init of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 was successful
14:55:31,068 DEBUG || - [MasterJobContext] hz.cocky_cohen.cached.thread-3 - Executing job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,068 INFO || - [JobExecutionService] hz.cocky_cohen.cached.thread-3 - Start execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 from coordinator [127.0.0.1]:5701
14:55:31,068 INFO || - [JobExecutionService] hz.romantic_cohen.generic-operation.thread-8 - Start execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 from coordinator [127.0.0.1]:5701
14:55:31,071 INFO || - [undertow] hz.romantic_cohen.jet.blocking.thread-0 - starting server: Undertow - 2.1.1.Final
14:55:31,134 DEBUG || - [JobRepository] hz.cocky_cohen.cached.thread-3 - Job cleanup took 2ms
14:55:31,260 DEBUG || - [EventSource] Time-limited test - readyState change: RAW -> CONNECTING
14:55:31,260 INFO || - [EventSource] Time-limited test - Starting EventSource client using URI: http://0.0.0.0:8081/
14:55:31,260 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - readyState change: CONNECTING -> CONNECTING
14:55:31,265 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - readyState change: CONNECTING -> OPEN
14:55:31,265 INFO || - [EventSource] okhttp-eventsource-stream-[]-0 - Connected to Event Source stream.
14:55:31,265 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-0
14:55:31,265 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,265 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-1
14:55:31,265 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-2
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-3
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-4
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-5
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-6
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-7
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-8
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-9
14:55:31,266 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-0
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-1
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-2
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-3
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,465 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-4
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-5
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-6
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-7
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-8
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line: data:message-9
14:55:31,466 DEBUG || - [EventParser] okhttp-eventsource-stream-[]-0 - Parsing line:
14:55:31,662 DEBUG || - [Job] Time-limited test - Sending CANCEL_FORCEFUL request for job 0568-d20c-ba40-0001 (name ??)
14:55:31,665 DEBUG || - [JobExecutionService] hz.cocky_cohen.jet.cooperative.thread-1 - Execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:392)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:378)
at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:346)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.run(OperationExecutorImpl.java:406)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.runOrExecute(OperationExecutorImpl.java:433)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:596)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:581)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:540)
at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:237)
at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:59)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipant(MasterContext.java:261)
at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:245)
at com.hazelcast.jet.impl.MasterJobContext.lambda$cancelExecutionInvocations$16(MasterJobContext.java:597)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:64)
at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:80)
14:55:31,666 DEBUG || - [JobExecutionService] hz.romantic_cohen.jet.cooperative.thread-4 - Execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607)
at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591)
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:392)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:378)
at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891)
at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:346)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235)
at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61)
at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216)
at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:422)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:166)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:136)
at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:123)
14:55:31,668 DEBUG || - [MasterJobContext] ForkJoinPool.commonPool-worker-91 - job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 to be cancelled after Execution
14:55:31,668 DEBUG || - [MasterJobContext] hz.cocky_cohen.cached.thread-2 - Sending CompleteExecutionOperation for job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,669 DEBUG || - [CompleteExecutionOperation] hz.cocky_cohen.cached.thread-2 - Completing execution 0568-d20c-ba41-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:55:31,669 DEBUG || - [JobExecutionService] hz.cocky_cohen.cached.thread-2 - Completed execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,670 DEBUG || - [CompleteExecutionOperation] hz.romantic_cohen.generic-operation.thread-13 - Completing execution 0568-d20c-ba41-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
14:55:31,670 INFO || - [undertow] hz.romantic_cohen.generic-operation.thread-13 - stopping server: Undertow - 2.1.1.Final
14:55:31,674 WARN || - [EventSource] okhttp-eventsource-stream-[]-0 - Connection unexpectedly closed.
14:55:31,674 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - readyState change: OPEN -> CLOSED
14:55:31,674 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - response closed
14:55:31,674 DEBUG || - [EventSource] okhttp-eventsource-stream-[]-0 - buffered source closed
14:55:31,674 INFO || - [EventSource] okhttp-eventsource-stream-[]-0 - Waiting 1211 milliseconds before reconnecting...
14:55:31,675 DEBUG || - [JobExecutionService] hz.romantic_cohen.generic-operation.thread-13 - Completed execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001
14:55:31,675 INFO || - [MasterJobContext] hz.cocky_cohen.cached.thread-2 - Execution of job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 got terminated, reason=java.util.concurrent.CancellationException
Start time: 2020-12-11T14:55:31.055
Duration: 620 ms
To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
14:55:31,676 DEBUG || - [JobCoordinationService] hz.cocky_cohen.cached.thread-2 - job '0568-d20c-ba40-0001', execution 0568-d20c-ba41-0001 is completed
14:55:31,863 DEBUG || - [EventSource] Time-limited test - readyState change: CLOSED -> SHUTDOWN
14:55:31,863 DEBUG || - [EventSource] Time-limited test - call cancelled
14:55:31,864 INFO || - [JetTestSupport] Time-limited test - Terminating instanceFactory in JetTestSupport.@After
14:55:31,864 INFO || - [LifecycleService] Thread-22 - [127.0.0.1]:5702 is SHUTTING_DOWN
14:55:31,866 WARN || - [Node] Thread-22 - Terminating forcefully...
14:55:31,866 INFO || - [Node] Thread-22 - Shutting down connection manager...
14:55:31,867 INFO || - [MockNetworkingService] Thread-22 - Removed connection to endpoint: [127.0.0.1]:5702, connection: MockConnection{localEndpoint=[127.0.0.1]:5701, remoteEndpoint=[127.0.0.1]:5702, alive=false}
14:55:31,867 INFO || - [MockNetworkingService] Thread-22 - Removed connection to endpoint: [127.0.0.1]:5701, connection: MockConnection{localEndpoint=[127.0.0.1]:5702, remoteEndpoint=[127.0.0.1]:5701, alive=false}
14:55:31,867 INFO || - [MembershipManager] Thread-22 - Removing Member [127.0.0.1]:5702 - 554463d5-6b5f-421f-9b52-67436107ffa4
14:55:31,868 INFO || - [TransactionManagerService] hz.cocky_cohen.cached.thread-2 - Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 554463d5-6b5f-421f-9b52-67436107ffa4
14:55:31,870 INFO || - [ClusterService] Thread-22 -
Members {size:1, ver:3} [
Member [127.0.0.1]:5701 - 71e8cd3c-d856-40a2-8aea-5c48e48f31cf this
]
14:55:31,870 INFO || - [Node] Thread-22 - Shutting down node engine...
14:55:31,947 INFO || - [NodeExtension] Thread-22 - Destroying node NodeExtension.
14:55:31,950 INFO || - [Node] Thread-22 - Hazelcast Shutdown is completed in 84 ms.
14:55:31,950 INFO || - [LifecycleService] Thread-22 - [127.0.0.1]:5702 is SHUTDOWN
14:55:31,950 INFO || - [LifecycleService] Thread-22 - [127.0.0.1]:5701 is SHUTTING_DOWN
14:55:31,952 WARN || - [Node] Thread-22 - Terminating forcefully...
14:55:31,952 INFO || - [Node] Thread-22 - Shutting down connection manager...
14:55:31,953 INFO || - [Node] Thread-22 - Shutting down node engine...
14:55:32,052 INFO || - [NodeExtension] Thread-22 - Destroying node NodeExtension.
14:55:32,053 INFO || - [Node] Thread-22 - Hazelcast Shutdown is completed in 101 ms.
14:55:32,053 INFO || - [LifecycleService] Thread-22 - [127.0.0.1]:5701 is SHUTDOWN
The text was updated successfully, but these errors were encountered:
master (commit b9a4415)
Failed on Oracle JDK 8: http://jenkins.hazelcast.com/view/Jet/job/jet-contrib-tests/269/testReport/junit/com.hazelcast.jet.contrib.http/HttpListenerSinkTest/testWebsocket_when_portConfigured/
Stacktrace:
Standard output:
The text was updated successfully, but these errors were encountered: