hazelcast-jet icon indicating copy to clipboard operation
hazelcast-jet copied to clipboard

com.hazelcast.jet.cdc.mysql.MySqlCdcIntegrationTest.customers fails on JDK 15

Open olukas opened this issue 3 years ago • 6 comments

master (commit c6423f9a5bbcf1b8f24f4a0d27e0484c9a218c93)

Failed on Zulu JDK 15: http://jenkins.hazelcast.com/view/Jet%20-%20Compatibility/job/jet-oss-master-zulu-jdk15/2/testReport/com.hazelcast.jet.cdc.mysql/MySqlCdcIntegrationTest/customers/

Stacktrace:

java.lang.AssertionError: expected:<4> but was:<0>
	at org.junit.Assert.fail(Assert.java:88)
	at org.junit.Assert.failNotEquals(Assert.java:834)
	at org.junit.Assert.assertEquals(Assert.java:118)
	at org.junit.Assert.assertEquals(Assert.java:144)
	at com.hazelcast.test.HazelcastTestSupport$9.run(HazelcastTestSupport.java:1125)
	at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1356)
	at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1458)
	at com.hazelcast.test.HazelcastTestSupport.assertEqualsEventually(HazelcastTestSupport.java:1122)
	at com.hazelcast.jet.cdc.mysql.MySqlCdcIntegrationTest.customers(MySqlCdcIntegrationTest.java:91)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	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.RunAfters.evaluate(RunAfters.java:27)
	at org.testcontainers.containers.FailureDetectingExternalResource$1.evaluate(FailureDetectingExternalResource.java:30)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	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.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.lang.Thread.run(Thread.java:832)

Standard output:

 o--o o---o   o
2020-10-27 11:37:30,571 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Copyright (c) 2008-2020, Hazelcast, Inc. All Rights Reserved.
2020-10-27 11:37:30,577 [ INFO] [Time-limited test] [c.h.i.m.i.MetricsConfigHelper]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled
2020-10-27 11:37:30,577 [ INFO] [Time-limited test] [c.h.s.i.o.i.BackpressureRegulator]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Backpressure is disabled
2020-10-27 11:37:30,585 [ WARN] [Time-limited test] [c.h.c.CPSubsystem]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] CP Subsystem is not enabled. CP data structures will operate in UNSAFE mode! Please note that UNSAFE mode will not provide strong consistency guarantees.
2020-10-27 11:37:30,593 [ INFO] [Time-limited test] [c.h.j.i.e.TaskletExecutionService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Creating idler with jet.idle.cooperative.min.microseconds=25?s,jet.idle.cooperative.max.microseconds=500?s
2020-10-27 11:37:30,593 [ INFO] [Time-limited test] [c.h.j.i.e.TaskletExecutionService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Creating idler with jet.idle.noncooperative.min.microseconds=25?s,jet.idle.noncooperative.max.microseconds=5000?s
2020-10-27 11:37:30,608 [ INFO] [Time-limited test] [c.h.j.i.JetService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Setting number of cooperative threads and default parallelism to 72
2020-10-27 11:37:30,609 [ INFO] [Time-limited test] [c.h.s.i.o.i.OperationExecutorImpl]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Starting 72 partition threads and 37 generic threads (1 dedicated for priority tasks)
2020-10-27 11:37:30,621 [ INFO] [Time-limited test] [c.h.i.d.Diagnostics]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
2020-10-27 11:37:30,622 [ INFO] [Time-limited test] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] [127.0.0.1]:5702 is STARTING
2020-10-27 11:37:30,625 [ INFO] [Time-limited test] [c.h.t.m.MockNetworkingService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] 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}
2020-10-27 11:37:30,638 [ INFO] [hz.silly_leavitt.priority-generic-operation.thread-0] [c.h.t.m.MockNetworkingService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] 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}
2020-10-27 11:37:30,642 [ INFO] [hz.silly_leavitt.priority-generic-operation.thread-0] [c.h.i.c.ClusterService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] 

Members {size:2, ver:2} [
	Member [127.0.0.1]:5701 - 52de5ad9-338e-4ab8-8617-1b0b4113c3d3 this
	Member [127.0.0.1]:5702 - 9048c9f2-70ae-463c-a265-bc62ecf683ee
]

2020-10-27 11:37:30,656 [ INFO] [hz.pedantic_leavitt.priority-generic-operation.thread-0] [c.h.i.c.ClusterService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] 

Members {size:2, ver:2} [
	Member [127.0.0.1]:5701 - 52de5ad9-338e-4ab8-8617-1b0b4113c3d3
	Member [127.0.0.1]:5702 - 9048c9f2-70ae-463c-a265-bc62ecf683ee this
]

2020-10-27 11:37:30,669 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2020-10-27 11:37:30,769 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2020-10-27 11:37:30,870 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2020-10-27 11:37:30,970 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2020-10-27 11:37:31,071 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2020-10-27 11:37:31,138 [ INFO] [Time-limited test] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] [127.0.0.1]:5702 is STARTED
2020-10-27 11:37:31,170 [ INFO] [hz.silly_leavitt.cached.thread-6] [c.h.i.p.i.PartitionStateManager]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Initializing cluster partition table arrangement...
2020-10-27 11:37:31,172 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2020-10-27 11:37:31,241 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.p.Planner]: Watermarks in the pipeline will be throttled to 1
2020-10-27 11:37:31,285 [ INFO] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Starting job 052e-b530-40c0-0001 based on submit request
2020-10-27 11:37:31,318 [ INFO] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Didn't find any snapshot to restore for job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,318 [ INFO] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Start executing job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001, execution graph in DOT format:
digraph DAG {
	"customers" [localParallelism=1];
	"filter_timestamps" [localParallelism=1];
	"map-stateful-keyed" [localParallelism=1];
	"mapSink(results)" [localParallelism=1];
	"customers" -> "filter_timestamps" [queueSize=1024];
	"filter_timestamps" -> "map-stateful-keyed" [label="distributed-partitioned", queueSize=1024];
	"map-stateful-keyed" -> "mapSink(results)" [label="partitioned", queueSize=1024];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
2020-10-27 11:37:31,318 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Building execution plan for job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,335 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 11ms
2020-10-27 11:37:31,341 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Built execution plans for job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,349 [DEBUG] [hz.pedantic_leavitt.generic-operation.thread-13] [c.h.j.i.o.InitExecutionOperation]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Initializing execution plan for job 052e-b530-40c0-0001, execution 052e-b530-40c1-0001 from [127.0.0.1]:5701
2020-10-27 11:37:31,353 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.o.InitExecutionOperation]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Initializing execution plan for job 052e-b530-40c0-0001, execution 052e-b530-40c1-0001 from [127.0.0.1]:5701
2020-10-27 11:37:31,429 [ INFO] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Execution plan for jobId=052e-b530-40c0-0001, jobName='052e-b530-40c0-0001', executionId=052e-b530-40c1-0001 initialized
2020-10-27 11:37:31,429 [ INFO] [hz.pedantic_leavitt.generic-operation.thread-13] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Execution plan for jobId=052e-b530-40c0-0001, jobName='052e-b530-40c0-0001', executionId=052e-b530-40c1-0001 initialized
2020-10-27 11:37:31,432 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Init of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 was successful
2020-10-27 11:37:31,432 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Executing job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,434 [ INFO] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Start execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 from coordinator [127.0.0.1]:5701
2020-10-27 11:37:31,434 [ INFO] [hz.pedantic_leavitt.generic-operation.thread-14] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Start execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 from coordinator [127.0.0.1]:5701
2020-10-27 11:37:31,498 [ WARN] [hz.silly_leavitt.jet.blocking.thread-0] [c.h.j.i.e.TaskletExecutionService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Exception in ProcessorTasklet{customers#1}
java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at io.debezium.config.Field$Validator.lambda$and$0(Field.java:214) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Field.validate(Field.java:545) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validate(Configuration.java:1829) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validateAndRecord(Configuration.java:1845) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:90) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at com.hazelcast.jet.cdc.impl.CdcSource.startNewTask(CdcSource.java:173) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.cdc.impl.CdcSource.isConnectionUp(CdcSource.java:135) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.cdc.impl.CdcSource.fillBuffer(CdcSource.java:102) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.function.BiConsumerEx.accept(BiConsumerEx.java:47) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.connector.ConvenientSourceP.complete(ConvenientSourceP.java:117) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.complete(ProcessorTasklet.java:467) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.stateMachineStep(ProcessorTasklet.java:367) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.call(ProcessorTasklet.java:242) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:293) [hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) [?:?]
	at java.lang.Thread.run(Thread.java:832) [?:?]
2020-10-27 11:37:31,514 [DEBUG] [hz.silly_leavitt.jet.cooperative.thread-4] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 completed with failure
java.util.concurrent.CompletionException: com.hazelcast.jet.JetException: Exception in ProcessorTasklet{customers#1}: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2152) ~[?:?]
	at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:392) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:378) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:807) [?:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:346) [hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: com.hazelcast.jet.JetException: Exception in ProcessorTasklet{customers#1}: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:304) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[?:?]
	... 1 more
Caused by: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at io.debezium.config.Field$Validator.lambda$and$0(Field.java:214) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Field.validate(Field.java:545) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validate(Configuration.java:1829) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validateAndRecord(Configuration.java:1845) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:90) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at com.hazelcast.jet.cdc.impl.CdcSource.startNewTask(CdcSource.java:173) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.cdc.impl.CdcSource.isConnectionUp(CdcSource.java:135) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.cdc.impl.CdcSource.fillBuffer(CdcSource.java:102) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.function.BiConsumerEx.accept(BiConsumerEx.java:47) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.connector.ConvenientSourceP.complete(ConvenientSourceP.java:117) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.complete(ProcessorTasklet.java:467) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.stateMachineStep(ProcessorTasklet.java:367) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.call(ProcessorTasklet.java:242) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:293) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[?:?]
	... 1 more
2020-10-27 11:37:31,551 [DEBUG] [hz.pedantic_leavitt.jet.cooperative.thread-7] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 completed with failure
java.util.concurrent.CompletionException: java.util.concurrent.CancellationException
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2152) ~[?:?]
	at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:461) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:392) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:378) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:807) [?:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:346) [hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: java.util.concurrent.CancellationException
	at java.util.concurrent.CompletableFuture.cancel(CompletableFuture.java:2468) ~[?:?]
	at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:233) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:184) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:227) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:216) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:422) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:166) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:136) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.run(OperationThread.java:123) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
2020-10-27 11:37:31,558 [DEBUG] [ForkJoinPool.commonPool-worker-231] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 has failures: [[127.0.0.1]:5702=java.util.concurrent.CancellationException, [127.0.0.1]:5701=com.hazelcast.jet.JetException: Exception in ProcessorTasklet{customers#1}: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')]
2020-10-27 11:37:31,560 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Sending CompleteExecutionOperation for job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,565 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.o.CompleteExecutionOperation]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Completing execution 052e-b530-40c1-0001 from caller [127.0.0.1]:5701, error=com.hazelcast.jet.JetException: Exception in ProcessorTasklet{customers#1}: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
2020-10-27 11:37:31,567 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Completed execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,566 [DEBUG] [hz.pedantic_leavitt.generic-operation.thread-17] [c.h.j.i.o.CompleteExecutionOperation]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Completing execution 052e-b530-40c1-0001 from caller [127.0.0.1]:5701, error=com.hazelcast.jet.JetException: Exception in ProcessorTasklet{customers#1}: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
2020-10-27 11:37:31,567 [DEBUG] [hz.pedantic_leavitt.generic-operation.thread-17] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Completed execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001
2020-10-27 11:37:31,573 [ERROR] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Execution of job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 failed
	Start time: 2020-10-27T11:37:31.286
	Duration: 282 ms
	To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
com.hazelcast.jet.JetException: Exception in ProcessorTasklet{customers#1}: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:304) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[?:?]
	at java.lang.Thread.run(Thread.java:832) ~[?:?]
Caused by: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1672/0x000000080110d8d0 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at io.debezium.config.Field$Validator.lambda$and$0(Field.java:214) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Field.validate(Field.java:545) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validate(Configuration.java:1829) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validateAndRecord(Configuration.java:1845) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:90) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at com.hazelcast.jet.cdc.impl.CdcSource.startNewTask(CdcSource.java:173) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.cdc.impl.CdcSource.isConnectionUp(CdcSource.java:135) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.cdc.impl.CdcSource.fillBuffer(CdcSource.java:102) ~[hazelcast-jet-cdc-debezium-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.function.BiConsumerEx.accept(BiConsumerEx.java:47) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.connector.ConvenientSourceP.complete(ConvenientSourceP.java:117) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.complete(ProcessorTasklet.java:467) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.stateMachineStep(ProcessorTasklet.java:367) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.call(ProcessorTasklet.java:242) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:293) ~[hazelcast-jet-4.4-SNAPSHOT.jar:4.4-SNAPSHOT]
	... 5 more
2020-10-27 11:37:31,581 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] job '052e-b530-40c0-0001', execution 052e-b530-40c1-0001 is completed
2020-10-27 11:37:36,342 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Deleting job resource map '__jet.resources.052e-b530-40c0-0001' because job is already finished
2020-10-27 11:37:36,348 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 7ms
2020-10-27 11:37:41,352 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:37:46,356 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:37:51,360 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:37:56,365 [DEBUG] [hz.silly_leavitt.cached.thread-8] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:01,370 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:06,374 [DEBUG] [hz.silly_leavitt.cached.thread-1] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:11,378 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:16,382 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:21,386 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:26,390 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:31,394 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:36,397 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 0ms
2020-10-27 11:38:41,401 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:38:46,405 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 0ms
2020-10-27 11:38:51,409 [DEBUG] [hz.silly_leavitt.cached.thread-6] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 0ms
2020-10-27 11:38:56,412 [DEBUG] [hz.silly_leavitt.cached.thread-8] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 0ms
2020-10-27 11:39:01,416 [DEBUG] [hz.silly_leavitt.cached.thread-1] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:06,419 [DEBUG] [hz.silly_leavitt.cached.thread-7] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:11,423 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:16,427 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:21,432 [DEBUG] [hz.silly_leavitt.cached.thread-8] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:26,437 [DEBUG] [hz.silly_leavitt.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:31,438 [ INFO] [Time-limited test] [c.h.j.c.JetTestSupport]: Terminating instanceFactory in JetTestSupport.@After
2020-10-27 11:39:31,440 [DEBUG] [hz.silly_leavitt.cached.thread-5] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Job cleanup took 1ms
2020-10-27 11:39:31,440 [ INFO] [Thread-2] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] [127.0.0.1]:5702 is SHUTTING_DOWN
2020-10-27 11:39:31,446 [ WARN] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Terminating forcefully...
2020-10-27 11:39:31,446 [ INFO] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Shutting down connection manager...
2020-10-27 11:39:31,447 [ INFO] [Thread-2] [c.h.t.m.MockNetworkingService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] 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}
2020-10-27 11:39:31,448 [ INFO] [Thread-2] [c.h.t.m.MockNetworkingService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] 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}
2020-10-27 11:39:31,448 [ INFO] [Thread-2] [c.h.i.c.i.MembershipManager]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Removing Member [127.0.0.1]:5702 - 9048c9f2-70ae-463c-a265-bc62ecf683ee
2020-10-27 11:39:31,451 [ INFO] [Thread-2] [c.h.i.c.ClusterService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] 

Members {size:1, ver:3} [
	Member [127.0.0.1]:5701 - 52de5ad9-338e-4ab8-8617-1b0b4113c3d3 this
]

2020-10-27 11:39:31,451 [ INFO] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Shutting down node engine...
2020-10-27 11:39:31,458 [ INFO] [hz.silly_leavitt.cached.thread-5] [c.h.t.TransactionManagerService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 9048c9f2-70ae-463c-a265-bc62ecf683ee
2020-10-27 11:39:31,481 [ INFO] [Thread-2] [c.h.i.i.NodeExtension]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Destroying node NodeExtension.
2020-10-27 11:39:31,481 [ INFO] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] Hazelcast Shutdown is completed in 35 ms.
2020-10-27 11:39:31,481 [ INFO] [Thread-2] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.4-SNAPSHOT] [127.0.0.1]:5702 is SHUTDOWN
2020-10-27 11:39:31,481 [ INFO] [Thread-2] [c.h.c.LifecycleService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] [127.0.0.1]:5701 is SHUTTING_DOWN
2020-10-27 11:39:31,484 [ WARN] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Terminating forcefully...
2020-10-27 11:39:31,484 [ INFO] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Shutting down connection manager...
2020-10-27 11:39:31,484 [ INFO] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Shutting down node engine...
2020-10-27 11:39:31,498 [ INFO] [Thread-2] [c.h.i.i.NodeExtension]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Destroying node NodeExtension.
2020-10-27 11:39:31,499 [ INFO] [Thread-2] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] Hazelcast Shutdown is completed in 15 ms.
2020-10-27 11:39:31,499 [ INFO] [Thread-2] [c.h.c.LifecycleService]: [127.0.0.1]:5701 [jet] [4.4-SNAPSHOT] [127.0.0.1]:5701 is SHUTDOWN
BuildInfo right after customers(com.hazelcast.jet.cdc.mysql.MySqlCdcIntegrationTest): BuildInfo{version='4.0.3', build='20200921', buildNumber=20200921, revision=59ae831, enterprise=false, serializationVersion=1, jet=JetBuildInfo{version='4.4-SNAPSHOT', build='20201027', revision='c6423f9'}}
Hiccups measured while running test 'customers(com.hazelcast.jet.cdc.mysql.MySqlCdcIntegrationTest):'
11:37:15, accumulated pauses: 17 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:37:20, accumulated pauses: 35 ms, max pause: 2 ms, pauses over 1000 ms: 0
11:37:25, accumulated pauses: 71 ms, max pause: 6 ms, pauses over 1000 ms: 0
11:37:30, accumulated pauses: 54 ms, max pause: 12 ms, pauses over 1000 ms: 0
11:37:35, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:37:40, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:37:45, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:37:50, accumulated pauses: 27 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:37:55, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:00, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:05, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:10, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:15, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:20, accumulated pauses: 27 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:25, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:30, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:35, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:40, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:45, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:50, accumulated pauses: 24 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:38:55, accumulated pauses: 25 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:39:00, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:39:05, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:39:10, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:39:15, accumulated pauses: 43 ms, max pause: 17 ms, pauses over 1000 ms: 0
11:39:20, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:39:25, accumulated pauses: 26 ms, max pause: 0 ms, pauses over 1000 ms: 0
11:39:30, accumulated pauses: 11 ms, max pause: 0 ms, pauses over 1000 ms: 0

olukas avatar Oct 29 '20 08:10 olukas

From this error it looks like the CDC connectors don't work on JDK 15. Do we want to dig deeper?

jbartok avatar Oct 29 '20 08:10 jbartok

Already fixed by Ondrej, the issue just remained open.

jbartok avatar Nov 17 '20 13:11 jbartok

Actually it's not fixed at all. I've just ignored those tests on JDK 15 to not block other tests. We still should investigate it and:

  • fix it if it's an issue on our side
  • report it to Debezium if it's not able to work with JDK 15 and document it somewhere.

=> reopening.

olukas avatar Nov 18 '20 09:11 olukas

Aha, ok, my misunderstanding, will investigate.

jbartok avatar Nov 18 '20 10:11 jbartok

The MySql connector doesn't work on Java 15, because it throws following error:

Caused by: java.lang.IllegalAccessError: class io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1855/0x0000000801135410 tried to access protected method 'int io.debezium.config.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(io.debezium.config.Configuration, io.debezium.config.Field, io.debezium.config.Field$ValidationOutput)' (io.debezium.connector.mysql.MySqlConnectorConfig$$Lambda$1855/0x0000000801135410 and io.debezium.config.CommonConnectorConfig are in unnamed module of loader 'app')
	at io.debezium.config.Field$Validator.lambda$and$0(Field.java:214) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Field.validate(Field.java:545) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validate(Configuration.java:1829) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.config.Configuration.validateAndRecord(Configuration.java:1845) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:90) ~[debezium-core-1.2.1.Final.jar:1.2.1.Final]
	at com.hazelcast.jet.cdc.impl.CdcSource.startNewTask(CdcSource.java:173) ~[classes/:?]
	at com.hazelcast.jet.cdc.impl.CdcSource.isConnectionUp(CdcSource.java:135) ~[classes/:?]
	at com.hazelcast.jet.cdc.impl.CdcSource.fillBuffer(CdcSource.java:102) ~[classes/:?]
	at com.hazelcast.function.BiConsumerEx.accept(BiConsumerEx.java:47) ~[hazelcast-4.1.1-20201106.130102-8.jar:4.1.1-SNAPSHOT]
	at com.hazelcast.jet.impl.connector.ConvenientSourceP.complete(ConvenientSourceP.java:117) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.complete(ProcessorTasklet.java:467) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.stateMachineStep(ProcessorTasklet.java:367) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.ProcessorTasklet.call(ProcessorTasklet.java:242) ~[classes/:?]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:293) ~[classes/:?]
	... 5 more

This happens because io.debezium.connector.mysql.MySqlConnectorConfig extends io.debezium.relational.CommonConnectorConfig calls io.debezium.relational.CommonConnectorConfig.validateServerNameIsDifferentFromHistoryTopicName(...).

This seems to be a JDK bug. I didn't find an exact match, as far as bug reports are concerned, but I've found this: JDK-8227415 : [nestmates] IllegalAccessError using a protected method reference declared in super class in different package

I recommend that we leave the "ignore on JDK 15" setting in the test and recheck, when a newer version of JDK 15 comes out.

I'll move the milestone to 4.5.

jbartok avatar Nov 19 '20 08:11 jbartok

About this issue: so the original failure is caused by a bug in JDK 15, which makes the Debezium code run by these tests throw an exception. There is nothing to fix on our side. We have just disabled these tests if the java version running them is detected as 15. We are keeping this issue open so that, when the JDK gets a new, fixed version, we re-enable the disabled tests again.

jbartok avatar Jan 18 '21 10:01 jbartok