Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

com.hazelcast.jet.cdc.mysql.MySqlCdcListenBeforeExistIntegrationTest.listenBeforeTableExists #3026

Open
olukas opened this issue Apr 14, 2021 · 0 comments
Open

com.hazelcast.jet.cdc.mysql.MySqlCdcListenBeforeExistIntegrationTest.listenBeforeTableExists #3026

olukas opened this issue Apr 14, 2021 · 0 comments
Labels
test-failure
Milestone
4.6

Comments

@olukas
Copy link
Collaborator

olukas commented Apr 14, 2021

master (commit bed77b2)

Failed on Nightly run with Oracle JDK 8: http://jenkins.hazelcast.com/job/jet-oss-master-nightly-oracle-jdk8/461/testReport/junit/com.hazelcast.jet.cdc.mysql/MySqlCdcListenBeforeExistIntegrationTest/listenBeforeTableExists/

Stacktrace:

java.lang.AssertionError: expected:<[1001/0:INSERT:TableRow {id=1001, value1=someValue1, value2=someValue2, value3=null}]> but was:<[]>
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.failNotEquals(Assert.java:835)
	at org.junit.Assert.assertEquals(Assert.java:120)
	at org.junit.Assert.assertEquals(Assert.java:146)
	at com.hazelcast.test.HazelcastTestSupport$9.run(HazelcastTestSupport.java:1016)
	at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1247)
	at com.hazelcast.test.HazelcastTestSupport.assertTrueEventually(HazelcastTestSupport.java:1349)
	at com.hazelcast.test.HazelcastTestSupport.assertEqualsEventually(HazelcastTestSupport.java:1013)
	at com.hazelcast.jet.cdc.mysql.MySqlCdcListenBeforeExistIntegrationTest.listenBeforeTableExists(MySqlCdcListenBeforeExistIntegrationTest.java:104)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	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:61)
	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.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:288)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:282)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)

Standard output:

2021-04-14 02:30:34,394 [ INFO] [Time-limited test] [d.3]]: Creating container for image: debezium/example-mysql:1.3
2021-04-14 02:30:36,205 [ INFO] [Time-limited test] [d.3]]: Starting container with ID: 91cacf659f65c03da253c4bcffd80b206472c23a57db73861986371031237e50
2021-04-14 02:30:37,737 [ INFO] [Time-limited test] [d.3]]: Container debezium/example-mysql:1.3 is starting: 91cacf659f65c03da253c4bcffd80b206472c23a57db73861986371031237e50
2021-04-14 02:30:37,757 [ INFO] [Time-limited test] [d.3]]: Waiting for database connection to become available at jdbc:mysql://172.17.0.1:37607/test using query 'SELECT 1'
2021-04-14 02:30:49,451 [ INFO] [Time-limited test] [d.3]]: Container is started (JDBC URL: jdbc:mysql://172.17.0.1:37607/test)
2021-04-14 02:30:49,451 [ INFO] [Time-limited test] [d.3]]: Container debezium/example-mysql:1.3 started in PT15.058S
2021-04-14 02:30:49,553 [ INFO] [Time-limited test] [c.h.i.m.i.MetricsConfigHelper]: [LOCAL] [jet] [4.6-SNAPSHOT] Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
2021-04-14 02:30:49,555 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Hazelcast Jet 4.6-SNAPSHOT (20210414 - bed77b2) starting at [127.0.0.1]:5701
2021-04-14 02:30:49,555 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Based on Hazelcast IMDG version: 4.2.0 (20210324 - 405cfd1)
2021-04-14 02:30:49,555 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Cluster name: jet
2021-04-14 02:30:49,555 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] 
	o   o   o   o---o o---o o     o---o   o   o---o o-o-o        o o---o o-o-o
	|   |  / \     /  |     |     |      / \  |       |          | |       |
	o---o o---o   o   o-o   |     o     o---o o---o   |          | o-o     |
	|   | |   |  /    |     |     |     |   |     |   |      \   | |       |
	o   o o   o o---o o---o o---o o---o o   o o---o   o       o--o o---o   o
2021-04-14 02:30:49,555 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Copyright (c) 2008-2021, Hazelcast, Inc. All Rights Reserved.
2021-04-14 02:30:49,558 [ INFO] [Time-limited test] [c.h.i.m.i.MetricsConfigHelper]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled
2021-04-14 02:30:49,651 [ WARN] [Time-limited test] [c.h.c.CPSubsystem]: [127.0.0.1]:5701 [jet] [4.6-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.
2021-04-14 02:30:49,986 [ INFO] [Time-limited test] [c.h.j.i.JetService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Setting number of cooperative threads and default parallelism to 72
2021-04-14 02:30:50,789 [ INFO] [Time-limited test] [c.h.i.d.Diagnostics]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
2021-04-14 02:30:50,789 [ INFO] [Time-limited test] [c.h.c.LifecycleService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5701 is STARTING
2021-04-14 02:30:50,790 [ INFO] [Time-limited test] [c.h.i.c.ClusterService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] 

Members {size:1, ver:1} [
	Member [127.0.0.1]:5701 - 9ca39940-da7a-4cba-ba22-5996ab7f641f this
]

2021-04-14 02:30:50,820 [DEBUG] [hz.hardcore_swartz.cached.thread-18] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:50,850 [ INFO] [Time-limited test] [c.h.c.LifecycleService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5701 is STARTED
2021-04-14 02:30:50,851 [ INFO] [Time-limited test] [c.h.i.m.i.MetricsConfigHelper]: [LOCAL] [jet] [4.6-SNAPSHOT] Overridden metrics configuration with system property 'hazelcast.metrics.collection.frequency'='1' -> 'MetricsConfig.collectionFrequencySeconds'='1'
2021-04-14 02:30:50,853 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Hazelcast Jet 4.6-SNAPSHOT (20210414 - bed77b2) starting at [127.0.0.1]:5702
2021-04-14 02:30:50,853 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Based on Hazelcast IMDG version: 4.2.0 (20210324 - 405cfd1)
2021-04-14 02:30:50,853 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Cluster name: jet
2021-04-14 02:30:50,853 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] 
	o   o   o   o---o o---o o     o---o   o   o---o o-o-o        o o---o o-o-o
	|   |  / \     /  |     |     |      / \  |       |          | |       |
	o---o o---o   o   o-o   |     o     o---o o---o   |          | o-o     |
	|   | |   |  /    |     |     |     |   |     |   |      \   | |       |
	o   o o   o o---o o---o o---o o---o o   o o---o   o       o--o o---o   o
2021-04-14 02:30:50,853 [ INFO] [Time-limited test] [c.h.system]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Copyright (c) 2008-2021, Hazelcast, Inc. All Rights Reserved.
2021-04-14 02:30:50,853 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=88.5G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=278.7M, heap.memory.free=697.8M, heap.memory.total=976.5M, heap.memory.max=976.5M, heap.memory.used/total=28.54%, heap.memory.used/max=28.54%, minor.gc.count=36, minor.gc.time=13625ms, major.gc.count=3, major.gc.time=4437ms, load.process=14.29%, load.system=100.00%, load.systemAverage=4736.94, thread.count=297, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=0, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=6, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:30:50,856 [ INFO] [Time-limited test] [c.h.i.m.i.MetricsConfigHelper]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Collecting debug metrics and sending to diagnostics is enabled
2021-04-14 02:30:50,869 [ WARN] [Time-limited test] [c.h.c.CPSubsystem]: [127.0.0.1]:5702 [jet] [4.6-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.
2021-04-14 02:30:50,928 [DEBUG] [hz.hardcore_swartz.cached.thread-13] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,028 [DEBUG] [hz.hardcore_swartz.cached.thread-13] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,129 [DEBUG] [hz.hardcore_swartz.cached.thread-13] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,169 [ INFO] [Time-limited test] [c.h.j.i.JetService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Setting number of cooperative threads and default parallelism to 72
2021-04-14 02:30:51,229 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,330 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,430 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,533 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,634 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,692 [ INFO] [Time-limited test] [c.h.i.d.Diagnostics]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Diagnostics disabled. To enable add -Dhazelcast.diagnostics.enabled=true to the JVM arguments.
2021-04-14 02:30:51,693 [ INFO] [Time-limited test] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5702 is STARTING
2021-04-14 02:30:51,695 [ INFO] [Time-limited test] [c.h.t.m.MockServer]: [127.0.0.1]:5702 [jet] [4.6-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}
2021-04-14 02:30:51,751 [DEBUG] [hz.hardcore_swartz.cached.thread-8] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,799 [ INFO] [hz.hardcore_swartz.priority-generic-operation.thread-0] [c.h.t.m.MockServer]: [127.0.0.1]:5701 [jet] [4.6-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}
2021-04-14 02:30:51,857 [DEBUG] [hz.hardcore_swartz.cached.thread-13] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:51,884 [ INFO] [hz.hardcore_swartz.priority-generic-operation.thread-0] [c.h.i.c.ClusterService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] 

Members {size:2, ver:2} [
	Member [127.0.0.1]:5701 - 9ca39940-da7a-4cba-ba22-5996ab7f641f this
	Member [127.0.0.1]:5702 - 537e108f-d8ab-4a63-90b4-f13173699091
]

2021-04-14 02:30:51,891 [ INFO] [hz.serene_swartz.priority-generic-operation.thread-0] [c.h.i.c.ClusterService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] 

Members {size:2, ver:2} [
	Member [127.0.0.1]:5701 - 9ca39940-da7a-4cba-ba22-5996ab7f641f
	Member [127.0.0.1]:5702 - 537e108f-d8ab-4a63-90b4-f13173699091 this
]

2021-04-14 02:30:51,989 [DEBUG] [hz.hardcore_swartz.cached.thread-13] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:52,090 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:52,192 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not starting jobs because partitions are not yet initialized.
2021-04-14 02:30:52,219 [ INFO] [Time-limited test] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5702 is STARTED
2021-04-14 02:30:52,235 [ INFO] [hz.hardcore_swartz.cached.thread-16] [c.h.i.p.i.PartitionStateManager]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Initializing cluster partition table arrangement...
2021-04-14 02:30:52,266 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=88.4G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=300.5M, heap.memory.free=676.0M, heap.memory.total=976.5M, heap.memory.max=976.5M, heap.memory.used/total=30.78%, heap.memory.used/max=30.78%, minor.gc.count=36, minor.gc.time=13625ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4736.94, thread.count=506, thread.peakCount=673, cluster.timeDiff=-7, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=11, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=6, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:30:52,563 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.p.Planner]: Watermarks in the pipeline will be throttled to 1
2021-04-14 02:30:52,594 [ INFO] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Starting job 0607-ccc1-0ec0-0001 based on submit request
2021-04-14 02:30:52,869 [ INFO] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Didn't find any snapshot to restore for job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:30:52,869 [ INFO] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Start executing job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001, execution graph in DOT format:
digraph DAG {
	"cdcMysql" [localParallelism=1];
	"filter_timestamps" [localParallelism=1];
	"map-stateful-keyed" [localParallelism=1];
	"mapSink(resultsMap)" [localParallelism=1];
	"cdcMysql" -> "filter_timestamps" [queueSize=1024];
	"filter_timestamps" -> "map-stateful-keyed" [label="distributed-partitioned", queueSize=1024];
	"map-stateful-keyed" -> "mapSink(resultsMap)" [label="partitioned", queueSize=1024];
}
HINT: You can use graphviz or http://viz-js.com to visualize the printed graph.
2021-04-14 02:30:52,869 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Building execution plan for job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:30:52,870 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Built execution plans for job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:30:52,871 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.o.InitExecutionOperation]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Initializing execution plan for job 0607-ccc1-0ec0-0001, execution 0607-ccc1-0ec1-0001 from [127.0.0.1]:5701
2021-04-14 02:30:52,877 [ INFO] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Execution plan for jobId=0607-ccc1-0ec0-0001, jobName='0607-ccc1-0ec0-0001', executionId=0607-ccc1-0ec1-0001 initialized
2021-04-14 02:30:52,886 [DEBUG] [hz.hardcore_swartz.cached.thread-13] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 135ms
2021-04-14 02:30:52,890 [DEBUG] [hz.serene_swartz.generic-operation.thread-11] [c.h.j.i.o.InitExecutionOperation]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Initializing execution plan for job 0607-ccc1-0ec0-0001, execution 0607-ccc1-0ec1-0001 from [127.0.0.1]:5701
2021-04-14 02:30:52,895 [ INFO] [hz.serene_swartz.generic-operation.thread-11] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Execution plan for jobId=0607-ccc1-0ec0-0001, jobName='0607-ccc1-0ec0-0001', executionId=0607-ccc1-0ec1-0001 initialized
2021-04-14 02:30:52,896 [DEBUG] [hz.hardcore_swartz.cached.thread-15] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Init of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001 was successful
2021-04-14 02:30:52,896 [DEBUG] [hz.hardcore_swartz.cached.thread-15] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Executing job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:30:52,896 [ INFO] [hz.hardcore_swartz.cached.thread-15] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Start execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001 from coordinator [127.0.0.1]:5701
2021-04-14 02:30:52,975 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [c.h.j.c.i.ChangeRecordCdcSourceP]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [0607-ccc1-0ec0-0001/cdcMysql#0] cdcMysql has 'retry strategy' set to 'max attempts = -1, interval function = IntervalFunction (constant of 1000ms)'
2021-04-14 02:30:52,975 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [c.h.j.c.i.ChangeRecordCdcSourceP]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [0607-ccc1-0ec0-0001/cdcMysql#0] cdcMysql has 'commit period' set to '10000000000'
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [c.h.j.c.i.ChangeRecordCdcSourceP]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [0607-ccc1-0ec0-0001/cdcMysql#0] cdcMysql has 'clear state on reconnect' set to 'false'
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]: Starting MySqlConnectorTask with configuration:
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    reconnect.behavior = max attempts = -1, interval function = IntervalFunction (constant of 1000ms)
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    connector.class = io.debezium.connector.mysql.MySqlConnector
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.user = debezium
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.server.name = dbserver1
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    sequence.extractor.class = com.hazelcast.jet.cdc.mysql.impl.MySqlSequenceExtractor
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    include.schema.changes = false
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.port = 37607
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    table.whitelist = testDb.someTable
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    tombstones.on.delete = false
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.hostname = 172.17.0.1
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.password = ********
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    name = cdcMysql
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    connect.keep.alive.interval.ms = 500
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.whitelist = testDb
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    connect.keep.alive = true
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    database.history = com.hazelcast.jet.cdc.impl.CdcSourceP$DatabaseHistoryImpl
2021-04-14 02:30:52,984 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.c.BaseSourceTask]:    connect.timeout.ms = 500
2021-04-14 02:30:53,016 [ INFO] [hz.serene_swartz.generic-operation.thread-13] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Start execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001 from coordinator [127.0.0.1]:5701
2021-04-14 02:30:53,040 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.m.MySqlConnectorTask]: Found no existing offset, so preparing to perform a snapshot
2021-04-14 02:30:53,046 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.u.Threads]: Requested thread factory for connector MySqlConnector, id = dbserver1 named = binlog-client
2021-04-14 02:30:53,087 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.u.Threads]: Requested thread factory for connector MySqlConnector, id = dbserver1 named = snapshot
2021-04-14 02:30:53,087 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.u.Threads]: Creating thread debezium-mysqlconnector-dbserver1-snapshot
2021-04-14 02:30:53,092 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Starting snapshot for jdbc:mysql://172.17.0.1:37607/?useInformationSchema=true&nullCatalogMeansCurrent=false&useSSL=false&useUnicode=true&characterEncoding=UTF-8&characterSetResults=UTF-8&zeroDateTimeBehavior=CONVERT_TO_NULL&connectTimeout=500 with user 'debezium' with locking mode 'minimal'
2021-04-14 02:30:53,112 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Snapshot is using user 'debezium' with these MySQL grants:
2021-04-14 02:30:53,112 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	GRANT SELECT, RELOAD, SHOW DATABASES, REPLICATION SLAVE, REPLICATION CLIENT ON *.* TO 'debezium'@'%'
2021-04-14 02:30:53,112 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: MySQL server variables related to change data capture:
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_cache_size                             = 32768                                        
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_checksum                               = CRC32                                        
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_direct_non_transactional_updates       = OFF                                          
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_error_action                           = ABORT_SERVER                                 
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_format                                 = ROW                                          
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_group_commit_sync_delay                = 0                                            
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_group_commit_sync_no_delay_count       = 0                                            
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_gtid_simple_recovery                   = ON                                           
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_max_flush_queue_time                   = 0                                            
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_order_commits                          = ON                                           
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_row_image                              = FULL                                         
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_rows_query_log_events                  = OFF                                          
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_stmt_cache_size                        = 32768                                        
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_transaction_dependency_history_size    = 25000                                        
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	binlog_transaction_dependency_tracking        = COMMIT_ORDER                                 
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_client                          = utf8mb4                                      
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_connection                      = utf8mb4                                      
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_database                        = latin1                                       
2021-04-14 02:30:53,122 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_filesystem                      = binary                                       
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_results                         = utf8mb4                                      
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_server                          = latin1                                       
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_set_system                          = utf8                                         
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	character_sets_dir                            = /usr/share/mysql/charsets/                   
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	collation_connection                          = utf8mb4_general_ci                           
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	collation_database                            = latin1_swedish_ci                            
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	collation_server                              = latin1_swedish_ci                            
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	enforce_gtid_consistency                      = OFF                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	gtid_executed_compression_period              = 1000                                         
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	gtid_mode                                     = OFF                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	gtid_next                                     = AUTOMATIC                                    
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	gtid_owned                                    =                                              
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	gtid_purged                                   =                                              
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	innodb_api_enable_binlog                      = OFF                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	innodb_locks_unsafe_for_binlog                = OFF                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	innodb_version                                = 5.7.33                                       
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	log_statements_unsafe_for_binlog              = ON                                           
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	max_binlog_cache_size                         = 18446744073709547520                         
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	max_binlog_size                               = 1073741824                                   
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	max_binlog_stmt_cache_size                    = 18446744073709547520                         
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	protocol_version                              = 10                                           
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	session_track_gtids                           = OFF                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	slave_type_conversions                        =                                              
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	sync_binlog                                   = 1                                            
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	system_time_zone                              = UTC                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	time_zone                                     = SYSTEM                                       
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	tls_version                                   = TLSv1,TLSv1.1,TLSv1.2                        
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	tx_isolation                                  = REPEATABLE-READ                              
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	tx_read_only                                  = OFF                                          
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	version                                       = 5.7.33-log                                   
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	version_comment                               = MySQL Community Server (GPL)                 
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	version_compile_machine                       = x86_64                                       
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	version_compile_os                            = Linux                                        
2021-04-14 02:30:53,126 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 0: disabling autocommit, enabling repeatable read transactions, and setting lock wait timeout to 10
2021-04-14 02:30:53,132 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 1: flush and obtain global read lock to prevent writes to database
2021-04-14 02:30:53,134 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 2: start transaction with consistent snapshot
2021-04-14 02:30:53,134 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 3: read binlog position of MySQL master
2021-04-14 02:30:53,135 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 using binlog 'mysql-bin.000003' at position '523' and gtid ''
2021-04-14 02:30:53,135 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 4: read list of available databases
2021-04-14 02:30:53,136 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 list of available databases is: [information_schema, inventory, mysql, performance_schema, sys, test, testDb]
2021-04-14 02:30:53,136 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 5: read list of available tables in each database
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'inventory.addresses' among known tables
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'inventory.addresses' is filtered out of capturing
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'inventory.customers' among known tables
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'inventory.customers' is filtered out of capturing
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'inventory.geom' among known tables
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'inventory.geom' is filtered out of capturing
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'inventory.orders' among known tables
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'inventory.orders' is filtered out of capturing
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'inventory.products' among known tables
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'inventory.products' is filtered out of capturing
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'inventory.products_on_hand' among known tables
2021-04-14 02:30:53,138 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'inventory.products_on_hand' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.columns_priv' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.columns_priv' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.db' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.db' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.engine_cost' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.engine_cost' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.event' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.event' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.func' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.func' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.general_log' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.general_log' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.gtid_executed' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.gtid_executed' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.help_category' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.help_category' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.help_keyword' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.help_keyword' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.help_relation' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.help_relation' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.help_topic' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.help_topic' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.innodb_index_stats' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.innodb_index_stats' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.innodb_table_stats' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.innodb_table_stats' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.ndb_binlog_index' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.ndb_binlog_index' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.plugin' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.plugin' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.proc' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.proc' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.procs_priv' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.procs_priv' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.proxies_priv' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.proxies_priv' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.server_cost' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.server_cost' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.servers' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.servers' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.slave_master_info' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.slave_master_info' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.slave_relay_log_info' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.slave_relay_log_info' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.slave_worker_info' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.slave_worker_info' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.slow_log' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.slow_log' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.tables_priv' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.tables_priv' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.time_zone' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.time_zone' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.time_zone_leap_second' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.time_zone_leap_second' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.time_zone_name' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.time_zone_name' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.time_zone_transition' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.time_zone_transition' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.time_zone_transition_type' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.time_zone_transition_type' is filtered out of capturing
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'mysql.user' among known tables
2021-04-14 02:30:53,139 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'mysql.user' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.accounts' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.accounts' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.cond_instances' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.cond_instances' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_current' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_current' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_history' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_history' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_history_long' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_history_long' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_summary_by_account_by_event_name' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_summary_by_account_by_event_name' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_summary_by_host_by_event_name' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_summary_by_host_by_event_name' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_summary_by_thread_by_event_name' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_summary_by_thread_by_event_name' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_summary_by_user_by_event_name' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_summary_by_user_by_event_name' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_stages_summary_global_by_event_name' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_stages_summary_global_by_event_name' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_statements_current' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_statements_current' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_statements_history' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_statements_history' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_statements_history_long' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.events_statements_history_long' is filtered out of capturing
2021-04-14 02:30:53,142 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.events_statements_summary_by_account_by_event_name' among known tables
2021-04-14 02:30:53,142 [ INFO] [debezium-
...[truncated 21875 chars]...
n tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.socket_instances' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.socket_summary_by_event_name' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.socket_summary_by_event_name' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.socket_summary_by_instance' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.socket_summary_by_instance' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.status_by_account' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.status_by_account' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.status_by_host' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.status_by_host' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.status_by_thread' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.status_by_thread' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.status_by_user' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.status_by_user' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.table_handles' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.table_handles' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.table_io_waits_summary_by_index_usage' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.table_io_waits_summary_by_index_usage' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.table_io_waits_summary_by_table' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.table_io_waits_summary_by_table' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.table_lock_waits_summary_by_table' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.table_lock_waits_summary_by_table' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.threads' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.threads' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.user_variables_by_thread' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.user_variables_by_thread' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.users' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.users' is filtered out of capturing
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'performance_schema.variables_by_thread' among known tables
2021-04-14 02:30:53,144 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'performance_schema.variables_by_thread' is filtered out of capturing
2021-04-14 02:30:53,147 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 including 'sys.sys_config' among known tables
2021-04-14 02:30:53,147 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	 'sys.sys_config' is filtered out of capturing
2021-04-14 02:30:53,149 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: 	snapshot continuing with database(s): [testDb]
2021-04-14 02:30:53,149 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 6: generating DROP and CREATE statements to reflect current database schemas:
2021-04-14 02:30:55,483 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 7: releasing global read lock to enable MySQL writes
2021-04-14 02:30:55,492 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 7: blocked writes to MySQL for a total of 00:00:02.358
2021-04-14 02:30:55,492 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 8: scanning contents of 0 tables while still in transaction
2021-04-14 02:30:55,492 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 8: scanned 0 rows in 0 tables in 00:00:00.0
2021-04-14 02:30:55,492 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Step 9: committing transaction
2021-04-14 02:30:55,499 [ INFO] [debezium-mysqlconnector-dbserver1-snapshot] [i.d.c.m.SnapshotReader]: Completed snapshot in 00:00:02.411
2021-04-14 02:30:55,546 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.m.ChainedReader]: Transitioning from the snapshot reader to the binlog reader
2021-04-14 02:30:55,547 [ WARN] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.r.RelationalDatabaseSchema]: After applying blacklist/whitelist filters there are no tables to monitor, please check your configuration
2021-04-14 02:30:55,580 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.u.Threads]: Creating thread debezium-mysqlconnector-dbserver1-binlog-client
2021-04-14 02:30:55,590 [ INFO] [blc-172.17.0.1:37607] [i.d.u.Threads]: Creating thread debezium-mysqlconnector-dbserver1-binlog-client
02:30:55.820 [&amp#27;[32m INFO&amp#27;[0m] [&amp#27;[34mc.g.s.m.b.BinaryLogClient&amp#27;[0m] Connected to 172.17.0.1:37607 at mysql-bin.000003/523 (sid:5417, cid:8)
2021-04-14 02:30:55,820 [ INFO] [blc-172.17.0.1:37607] [i.d.c.m.BinlogReader]: Connected to MySQL binlog at 172.17.0.1:37607, starting at binlog file 'mysql-bin.000003', pos=523, skipping 0 events plus 0 rows
2021-04-14 02:30:55,821 [ INFO] [blc-172.17.0.1:37607] [i.d.u.Threads]: Creating thread debezium-mysqlconnector-dbserver1-binlog-client
2021-04-14 02:30:55,821 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.m.BinlogReader]: Waiting for keepalive thread to start
02:30:56.776 [&amp#27;[32m INFO&amp#27;[0m] [&amp#27;[34mc.g.s.m.b.BinaryLogClient&amp#27;[0m] Trying to restore lost connection to 172.17.0.1:37607
2021-04-14 02:30:56,783 [ INFO] [blc-172.17.0.1:37607] [i.d.c.m.BinlogReader]: Stopped reading binlog after 0 events, no new offset was recorded
2021-04-14 02:30:56,783 [ INFO] [blc-keepalive-172.17.0.1:37607] [i.d.u.Threads]: Creating thread debezium-mysqlconnector-dbserver1-binlog-client
02:30:56.943 [&amp#27;[32m INFO&amp#27;[0m] [&amp#27;[34mc.g.s.m.b.BinaryLogClient&amp#27;[0m] Connected to 172.17.0.1:37607 at mysql-bin.000003/1285 (sid:5417, cid:9)
2021-04-14 02:30:56,944 [ INFO] [blc-172.17.0.1:37607] [i.d.c.m.BinlogReader]: Connected to MySQL binlog at 172.17.0.1:37607, starting at binlog file 'mysql-bin.000003', pos=1285, skipping 1 events plus 0 rows
2021-04-14 02:30:58,018 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 66ms
2021-04-14 02:31:00,834 [ INFO] [hz.hardcore_swartz.jet.blocking.thread-0] [i.d.c.m.BinlogReader]: 1 records sent during previous 00:00:05.253, last recorded offset: {ts_sec=1618367455, file=mysql-bin.000003, pos=1058, row=1, server_id=223344, event=2}
2021-04-14 02:31:00,836 [ INFO] [hz.hardcore_swartz.jet.cooperative.thread-5] [c.h.j.i.p.TransformStatefulP]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [0607-ccc1-0ec0-0001/map-stateful-keyed#0] Output to ordinal 0: Watermark{ts=02:30:55.896}
2021-04-14 02:31:00,837 [ INFO] [hz.serene_swartz.jet.cooperative.thread-6] [c.h.j.i.p.TransformStatefulP]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] [0607-ccc1-0ec0-0001/map-stateful-keyed#1] Output to ordinal 0: Watermark{ts=02:30:55.896}
2021-04-14 02:31:01,903 [DEBUG] [hz.hardcore_swartz.cached.thread-17] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Not scaling up job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001: not running or already running on all members
2021-04-14 02:31:03,059 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 13ms
2021-04-14 02:31:08,138 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 11ms
2021-04-14 02:31:10,860 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=88.5G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=259.9M, heap.memory.free=715.6M, heap.memory.total=975.5M, heap.memory.max=975.5M, heap.memory.used/total=26.64%, heap.memory.used/max=26.64%, minor.gc.count=37, minor.gc.time=14099ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4731.68, thread.count=520, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=2950, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:31:12,271 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=88.5G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=273.7M, heap.memory.free=701.8M, heap.memory.total=975.5M, heap.memory.max=975.5M, heap.memory.used/total=28.05%, heap.memory.used/max=28.05%, minor.gc.count=37, minor.gc.time=14099ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4731.68, thread.count=520, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=4048, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:31:13,164 [DEBUG] [hz.hardcore_swartz.cached.thread-3] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 7ms
2021-04-14 02:31:18,187 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 12ms
2021-04-14 02:31:23,210 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 14ms
2021-04-14 02:31:28,313 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 21ms
2021-04-14 02:31:30,864 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=85.7G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=174.9M, heap.memory.free=802.6M, heap.memory.total=977.5M, heap.memory.max=977.5M, heap.memory.used/total=17.89%, heap.memory.used/max=17.89%, minor.gc.count=38, minor.gc.time=14274ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4716.40, thread.count=519, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=6312, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:31:32,280 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=85.7G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=185.7M, heap.memory.free=791.8M, heap.memory.total=977.5M, heap.memory.max=977.5M, heap.memory.used/total=19.00%, heap.memory.used/max=19.00%, minor.gc.count=38, minor.gc.time=14274ms, major.gc.count=3, major.gc.time=4437ms, load.process=7.69%, load.system=100.00%, load.systemAverage=4716.40, thread.count=519, thread.peakCount=673, cluster.timeDiff=-1, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=7963, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:31:33,351 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 19ms
2021-04-14 02:31:38,416 [DEBUG] [hz.hardcore_swartz.cached.thread-12] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 14ms
2021-04-14 02:31:43,514 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 34ms
2021-04-14 02:31:48,571 [DEBUG] [hz.hardcore_swartz.cached.thread-3] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 43ms
2021-04-14 02:31:50,869 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=88.1G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=336.1M, heap.memory.free=641.4M, heap.memory.total=977.5M, heap.memory.max=977.5M, heap.memory.used/total=34.38%, heap.memory.used/max=34.38%, minor.gc.count=38, minor.gc.time=14274ms, major.gc.count=3, major.gc.time=4437ms, load.process=12.50%, load.system=100.00%, load.systemAverage=4687.56, thread.count=511, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=9676, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:31:52,291 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=87.9G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=343.8M, heap.memory.free=633.7M, heap.memory.total=977.5M, heap.memory.max=977.5M, heap.memory.used/total=35.17%, heap.memory.used/max=35.17%, minor.gc.count=38, minor.gc.time=14274ms, major.gc.count=3, major.gc.time=4437ms, load.process=7.14%, load.system=100.00%, load.systemAverage=4687.56, thread.count=510, thread.peakCount=673, cluster.timeDiff=-1, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=1, executor.q.priorityOperation.size=0, operations.completed.count=11745, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:31:53,736 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 66ms
2021-04-14 02:31:58,784 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 15ms
2021-04-14 02:32:03,813 [DEBUG] [hz.hardcore_swartz.cached.thread-17] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 14ms
2021-04-14 02:32:08,916 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 74ms
2021-04-14 02:32:10,878 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=86.9G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=248.2M, heap.memory.free=728.3M, heap.memory.total=976.5M, heap.memory.max=976.5M, heap.memory.used/total=25.42%, heap.memory.used/max=25.42%, minor.gc.count=39, minor.gc.time=14360ms, major.gc.count=3, major.gc.time=4437ms, load.process=3.70%, load.system=100.00%, load.systemAverage=4733.08, thread.count=506, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=12986, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:32:12,296 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=87.6G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=259.2M, heap.memory.free=717.3M, heap.memory.total=976.5M, heap.memory.max=976.5M, heap.memory.used/total=26.54%, heap.memory.used/max=26.54%, minor.gc.count=39, minor.gc.time=14360ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4733.08, thread.count=505, thread.peakCount=673, cluster.timeDiff=-1, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=15660, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:32:13,949 [DEBUG] [hz.hardcore_swartz.cached.thread-12] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 15ms
2021-04-14 02:32:18,988 [DEBUG] [hz.hardcore_swartz.cached.thread-17] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 3ms
2021-04-14 02:32:24,019 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 10ms
2021-04-14 02:32:29,072 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 12ms
2021-04-14 02:32:30,884 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=85.8G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=164.3M, heap.memory.free=815.2M, heap.memory.total=979.5M, heap.memory.max=979.5M, heap.memory.used/total=16.78%, heap.memory.used/max=16.78%, minor.gc.count=40, minor.gc.time=14605ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4685.18, thread.count=500, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=16267, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:32:32,303 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=85.4G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=172.2M, heap.memory.free=807.3M, heap.memory.total=979.5M, heap.memory.max=979.5M, heap.memory.used/total=17.58%, heap.memory.used/max=17.58%, minor.gc.count=40, minor.gc.time=14605ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4685.18, thread.count=500, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=19577, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:32:34,144 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 16ms
2021-04-14 02:32:39,164 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 2ms
2021-04-14 02:32:44,277 [DEBUG] [hz.hardcore_swartz.cached.thread-1] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 87ms
2021-04-14 02:32:49,332 [DEBUG] [hz.hardcore_swartz.cached.thread-16] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 10ms
2021-04-14 02:32:50,889 [ INFO] [hz.hardcore_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=85.9G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=322.8M, heap.memory.free=656.7M, heap.memory.total=979.5M, heap.memory.max=979.5M, heap.memory.used/total=32.95%, heap.memory.used/max=32.95%, minor.gc.count=40, minor.gc.time=14605ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4642.59, thread.count=504, thread.peakCount=673, cluster.timeDiff=0, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=19630, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:32:52,310 [ INFO] [hz.serene_swartz.HealthMonitor] [c.h.i.d.HealthMonitor]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] processors=72, physical.memory.total=377.6G, physical.memory.free=85.8G, swap.space.total=4.0G, swap.space.free=3.4G, heap.memory.used=332.9M, heap.memory.free=646.6M, heap.memory.total=979.5M, heap.memory.max=979.5M, heap.memory.used/total=33.98%, heap.memory.used/max=33.98%, minor.gc.count=40, minor.gc.time=14605ms, major.gc.count=3, major.gc.time=4437ms, load.process=0.00%, load.system=100.00%, load.systemAverage=4642.59, thread.count=504, thread.peakCount=673, cluster.timeDiff=-5, event.q.size=0, executor.q.async.size=0, executor.q.client.size=0, executor.q.client.query.size=0, executor.q.client.blocking.size=0, executor.q.query.size=0, executor.q.scheduled.size=0, executor.q.io.size=0, executor.q.system.size=0, executor.q.operations.size=0, executor.q.priorityOperation.size=0, operations.completed.count=23495, executor.q.mapLoad.size=0, executor.q.mapLoadAllKeys.size=0, executor.q.cluster.size=0, executor.q.response.size=0, operations.running.count=0, operations.pending.invocations.percentage=0.00%, operations.pending.invocations.count=0, proxy.count=7, clientEndpoint.count=0, connection.active.count=0, client.connection.count=0, connection.count=0
2021-04-14 02:32:54,411 [DEBUG] [hz.hardcore_swartz.cached.thread-11] [c.h.j.i.JobRepository]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Job cleanup took 24ms
2021-04-14 02:32:55,630 [DEBUG] [Time-limited test] [c.h.j.Job]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Sending CANCEL_FORCEFUL request for job 0607-ccc1-0ec0-0001 (name ??)
2021-04-14 02:32:55,645 [DEBUG] [hz.serene_swartz.jet.cooperative.thread-6] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-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) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) ~[?:1.8.0_251]
	at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:468) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.dismissTasklet(TaskletExecutionService.java:399) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.runTasklet(TaskletExecutionService.java:385) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) [?:1.8.0_251]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$CooperativeWorker.run(TaskletExecutionService.java:347) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_251]
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
	at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:189) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:272) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:248) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:469) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:197) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:137) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.executeRun(OperationThread.java:123) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:102) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
2021-04-14 02:32:56,560 [DEBUG] [hz.hardcore_swartz.jet.blocking.thread-0] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-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) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:607) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:591) ~[?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) [?:1.8.0_251]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) [?:1.8.0_251]
	at com.hazelcast.jet.impl.util.NonCompletableFuture.internalCompleteExceptionally(NonCompletableFuture.java:59) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$ExecutionTracker.taskletDone(TaskletExecutionService.java:468) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.execution.TaskletExecutionService$BlockingWorker.run(TaskletExecutionService.java:310) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_251]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_251]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_251]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_251]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_251]
Caused by: com.hazelcast.jet.impl.exception.JobTerminateRequestedException: CANCEL_FORCEFUL
	at com.hazelcast.jet.impl.execution.ExecutionContext.terminateExecution(ExecutionContext.java:235) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.operation.TerminateExecutionOperation.run(TerminateExecutionOperation.java:61) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.Operation.call(Operation.java:189) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:272) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:248) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:213) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.run(OperationExecutorImpl.java:411) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationExecutorImpl.runOrExecute(OperationExecutorImpl.java:438) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvokeLocal(Invocation.java:600) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:579) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke0(Invocation.java:540) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.invoke(Invocation.java:240) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.InvocationBuilderImpl.invoke(InvocationBuilderImpl.java:59) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.MasterContext.invokeOnParticipant(MasterContext.java:264) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.MasterContext.invokeOnParticipants(MasterContext.java:247) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.jet.impl.MasterJobContext.lambda$cancelExecutionInvocations$16(MasterJobContext.java:601) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_251]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_251]
	at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_251]
	at com.hazelcast.internal.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:102) ~[hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
2021-04-14 02:32:56,592 [DEBUG] [ForkJoinPool.commonPool-worker-55] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001 to be cancelled after Execution
2021-04-14 02:32:56,592 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Sending CompleteExecutionOperation for job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:32:56,592 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.o.CompleteExecutionOperation]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Completing execution 0607-ccc1-0ec1-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
2021-04-14 02:32:56,592 [ INFO] [hz.hardcore_swartz.cached.thread-14] [i.d.c.c.BaseSourceTask]: Stopping down connector
2021-04-14 02:32:56,592 [ INFO] [hz.hardcore_swartz.cached.thread-14] [i.d.c.m.MySqlConnectorTask]: Stopping MySQL connector task
2021-04-14 02:32:56,603 [ INFO] [hz.hardcore_swartz.cached.thread-14] [i.d.c.m.ChainedReader]: ChainedReader: Stopping the binlog reader
2021-04-14 02:32:56,603 [ INFO] [hz.hardcore_swartz.cached.thread-14] [i.d.c.m.BinlogReader]: Discarding 0 unsent record(s) due to the connector shutting down
2021-04-14 02:32:56,654 [ INFO] [blc-172.17.0.1:37607] [i.d.c.m.BinlogReader]: Stopped reading binlog after 1 events, last recorded offset: {ts_sec=1618367455, file=mysql-bin.000003, pos=1058, row=1, server_id=223344, event=2}
2021-04-14 02:32:56,667 [ INFO] [hz.hardcore_swartz.cached.thread-14] [i.d.c.m.BinlogReader]: Discarding 0 unsent record(s) due to the connector shutting down
2021-04-14 02:32:56,709 [ INFO] [hz.hardcore_swartz.cached.thread-14] [i.d.c.m.MySqlConnectorTask]: Connector task finished all work and is now shutdown
2021-04-14 02:32:56,709 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Completed execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:32:56,719 [DEBUG] [hz.serene_swartz.generic-operation.thread-1] [c.h.j.i.o.CompleteExecutionOperation]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Completing execution 0607-ccc1-0ec1-0001 from caller [127.0.0.1]:5701, error=java.util.concurrent.CancellationException
2021-04-14 02:32:56,719 [DEBUG] [hz.serene_swartz.generic-operation.thread-1] [c.h.j.i.JobExecutionService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Completed execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001
2021-04-14 02:32:56,720 [ INFO] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.MasterJobContext]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Execution of job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001 got terminated, reason=java.util.concurrent.CancellationException
	Start time: 2021-04-14T02:30:52.594
	Duration: 00:02:04.125
	To see additional job metrics enable JobConfig.storeMetricsAfterJobCompletion
2021-04-14 02:32:56,721 [DEBUG] [hz.hardcore_swartz.cached.thread-14] [c.h.j.i.JobCoordinationService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] job '0607-ccc1-0ec0-0001', execution 0607-ccc1-0ec1-0001 is completed
2021-04-14 02:32:56,722 [ INFO] [Time-limited test] [c.h.j.c.JetTestSupport]: Terminating instanceFactory in JetTestSupport.@After
2021-04-14 02:32:56,727 [ INFO] [Thread-91] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5702 is SHUTTING_DOWN
2021-04-14 02:32:56,728 [ WARN] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Terminating forcefully...
2021-04-14 02:32:56,728 [ INFO] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Shutting down connection manager...
2021-04-14 02:32:56,737 [ INFO] [Thread-91] [c.h.t.m.MockServer]: [127.0.0.1]:5701 [jet] [4.6-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}
2021-04-14 02:32:56,737 [ INFO] [Thread-91] [c.h.t.m.MockServer]: [127.0.0.1]:5702 [jet] [4.6-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}
2021-04-14 02:32:56,737 [ INFO] [Thread-91] [c.h.i.c.i.MembershipManager]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Removing Member [127.0.0.1]:5702 - 537e108f-d8ab-4a63-90b4-f13173699091
2021-04-14 02:32:56,738 [ INFO] [Thread-91] [c.h.i.c.ClusterService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] 

Members {size:1, ver:3} [
	Member [127.0.0.1]:5701 - 9ca39940-da7a-4cba-ba22-5996ab7f641f this
]

2021-04-14 02:32:56,738 [ INFO] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Shutting down node engine...
2021-04-14 02:32:56,875 [ INFO] [hz.hardcore_swartz.cached.thread-18] [c.h.t.TransactionManagerService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Committing/rolling-back live transactions of [127.0.0.1]:5702, UUID: 537e108f-d8ab-4a63-90b4-f13173699091
2021-04-14 02:32:57,354 [ INFO] [Thread-91] [c.h.i.i.NodeExtension]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Destroying node NodeExtension.
2021-04-14 02:32:57,359 [ INFO] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] Hazelcast Shutdown is completed in 631 ms.
2021-04-14 02:32:57,359 [ INFO] [Thread-91] [c.h.c.LifecycleService]: [127.0.0.1]:5702 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5702 is SHUTDOWN
2021-04-14 02:32:57,359 [ INFO] [Thread-91] [c.h.c.LifecycleService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5701 is SHUTTING_DOWN
2021-04-14 02:32:57,360 [ WARN] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Terminating forcefully...
2021-04-14 02:32:57,360 [ INFO] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Shutting down connection manager...
2021-04-14 02:32:57,368 [ INFO] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Shutting down node engine...
2021-04-14 02:32:57,470 [ WARN] [hz.hardcore_swartz.priority-generic-operation.thread-0] [c.h.s.i.o.i.Invocation]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Future.complete(Object) on completed future. Request: Invocation{op=com.hazelcast.internal.partition.operation.PromotionCommitOperation{serviceName='hz:core:partitionService', identityHash=141668534, partitionId=-1, replicaIndex=0, callId=-5044, invocationTime=1618367576951 (2021-04-14 02:32:56.951), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0}, tryCount=2147483647, tryPauseMillis=500, invokeCount=1, callTimeoutMillis=60000, firstInvocationTimeMs=1618367576951, firstInvocationTime='2021-04-14 02:32:56.951', 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: true
java.lang.Exception: null
	at com.hazelcast.spi.impl.AbstractInvocationFuture.warnIfSuspiciousDoubleCompletion(AbstractInvocationFuture.java:1253) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.AbstractInvocationFuture.complete0(AbstractInvocationFuture.java:1230) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.AbstractInvocationFuture.complete(AbstractInvocationFuture.java:1219) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.complete(Invocation.java:672) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.Invocation.sendResponse(Invocation.java:235) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.Operation.sendResponse(Operation.java:475) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.call(OperationRunnerImpl.java:282) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:248) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationservice.impl.OperationRunnerImpl.run(OperationRunnerImpl.java:213) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:175) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.process(OperationThread.java:139) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.spi.impl.operationexecutor.impl.OperationThread.executeRun(OperationThread.java:123) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
	at com.hazelcast.internal.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:102) [hazelcast-jet-4.6-SNAPSHOT.jar:4.6-SNAPSHOT]
2021-04-14 02:32:57,935 [ INFO] [Thread-91] [c.h.i.i.NodeExtension]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Destroying node NodeExtension.
2021-04-14 02:32:57,939 [ INFO] [Thread-91] [c.h.i.i.Node]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] Hazelcast Shutdown is completed in 579 ms.
2021-04-14 02:32:57,939 [ INFO] [Thread-91] [c.h.c.LifecycleService]: [127.0.0.1]:5701 [jet] [4.6-SNAPSHOT] [127.0.0.1]:5701 is SHUTDOWN
BuildInfo right after listenBeforeTableExists(com.hazelcast.jet.cdc.mysql.MySqlCdcListenBeforeExistIntegrationTest): BuildInfo{version='4.2', build='20210324', buildNumber=20210324, revision=405cfd1, enterprise=false, serializationVersion=1, jet=JetBuildInfo{version='4.6-SNAPSHOT', build='20210414', revision='bed77b2'}}
Hiccups measured while running test 'listenBeforeTableExists(com.hazelcast.jet.cdc.mysql.MySqlCdcListenBeforeExistIntegrationTest):'
02:30:30, accumulated pauses: 980 ms, max pause: 18 ms, pauses over 1000 ms: 0
02:30:35, accumulated pauses: 741 ms, max pause: 37 ms, pauses over 1000 ms: 0
02:30:40, accumulated pauses: 287 ms, max pause: 12 ms, pauses over 1000 ms: 0
02:30:45, accumulated pauses: 693 ms, max pause: 21 ms, pauses over 1000 ms: 0
02:30:50, accumulated pauses: 1612 ms, max pause: 269 ms, pauses over 1000 ms: 0
02:30:55, accumulated pauses: 1386 ms, max pause: 876 ms, pauses over 1000 ms: 0
02:31:00, accumulated pauses: 332 ms, max pause: 27 ms, pauses over 1000 ms: 0
02:31:05, accumulated pauses: 275 ms, max pause: 10 ms, pauses over 1000 ms: 0
02:31:10, accumulated pauses: 451 ms, max pause: 21 ms, pauses over 1000 ms: 0
02:31:15, accumulated pauses: 737 ms, max pause: 35 ms, pauses over 1000 ms: 0
02:31:20, accumulated pauses: 222 ms, max pause: 6 ms, pauses over 1000 ms: 0
02:31:25, accumulated pauses: 507 ms, max pause: 192 ms, pauses over 1000 ms: 0
02:31:30, accumulated pauses: 761 ms, max pause: 34 ms, pauses over 1000 ms: 0
02:31:35, accumulated pauses: 941 ms, max pause: 48 ms, pauses over 1000 ms: 0
02:31:40, accumulated pauses: 993 ms, max pause: 29 ms, pauses over 1000 ms: 0
02:31:45, accumulated pauses: 872 ms, max pause: 90 ms, pauses over 1000 ms: 0
02:31:50, accumulated pauses: 913 ms, max pause: 24 ms, pauses over 1000 ms: 0
02:31:55, accumulated pauses: 1576 ms, max pause: 165 ms, pauses over 1000 ms: 0
02:32:00, accumulated pauses: 1157 ms, max pause: 64 ms, pauses over 1000 ms: 0
02:32:05, accumulated pauses: 710 ms, max pause: 24 ms, pauses over 1000 ms: 0
02:32:10, accumulated pauses: 913 ms, max pause: 25 ms, pauses over 1000 ms: 0
02:32:15, accumulated pauses: 611 ms, max pause: 13 ms, pauses over 1000 ms: 0
02:32:20, accumulated pauses: 822 ms, max pause: 59 ms, pauses over 1000 ms: 0
02:32:25, accumulated pauses: 988 ms, max pause: 319 ms, pauses over 1000 ms: 0
02:32:30, accumulated pauses: 837 ms, max pause: 23 ms, pauses over 1000 ms: 0
02:32:35, accumulated pauses: 662 ms, max pause: 30 ms, pauses over 1000 ms: 0
02:32:40, accumulated pauses: 1244 ms, max pause: 81 ms, pauses over 1000 ms: 0
02:32:45, accumulated pauses: 751 ms, max pause: 39 ms, pauses over 1000 ms: 0
02:32:50, accumulated pauses: 1739 ms, max pause: 52 ms, pauses over 1000 ms: 0
02:32:55, accumulated pauses: 1699 ms, max pause: 119 ms, pauses over 1000 ms: 0
02:33:00, accumulated pauses: 882 ms, max pause: 39 ms, pauses over 1000 ms: 0
02:33:05, accumulated pauses: 98 ms, max pause: 10 ms, pauses over 1000 ms: 0
@olukas olukas added this to the 4.6 milestone Apr 14, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
test-failure
Projects
None yet
Milestone
4.6
Development

No branches or pull requests
1 participant
@olukas