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

DBZ-2975: Fix inconsistent test failure due NullPointerException #44

Merged
merged 1 commit into from
Apr 19, 2021
Merged

DBZ-2975: Fix inconsistent test failure due NullPointerException #44

merged 1 commit into from
Apr 19, 2021

Conversation

morozov
Copy link

@morozov morozov commented Apr 18, 2021 •
edited

The absence of this condition leads to sporadic test failures caused by a NullPointerException:

 java.lang.NullPointerException
 	at io.debezium.connector.sqlserver.SqlServerOffsetContext.eventsStreamed(SqlServerOffsetContext.java:225)
 	at io.debezium.pipeline.spi.StreamingResult.eventsStreamed(StreamingResult.java:21)
 	at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:150)
 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
 	at java.base/java.lang.Thread.run(Thread.java:834)

Could be reproduced for example via SqlServerConnectorIT#shouldPropagateSourceTypeByDatatype.

@morozov
Copy link
Author

morozov commented Apr 18, 2021 •
edited

We may consider improving this code even more (see #46).

@morozov morozov mentioned this pull request Apr 18, 2021
Closed
@morozov
Copy link
Author

morozov commented Apr 19, 2021 •
edited

Latest failures:

2021-04-19T01:45:42.8328694Z [ERROR] Tests run: 42, Failures: 1, Errors: 0, Skipped: 1, Time elapsed: 1,362.849 s <<< FAILURE! - in io.debezium.connector.sqlserver.SqlServerConnectorIT
2021-04-19T01:45:42.8339526Z [ERROR] excludeColumnWhenCaptureInstanceExcludesColumns(io.debezium.connector.sqlserver.SqlServerConnectorIT)  Time elapsed: 38.578 s  <<< FAILURE!
2021-04-19T01:45:42.8345838Z java.lang.AssertionError: expecting actual value not to be null
2021-04-19T01:45:42.8358841Z 	at io.debezium.connector.sqlserver.SqlServerConnectorIT.lambda$excludeColumnWhenCaptureInstanceExcludesColumns$60(SqlServerConnectorIT.java:1680)
2021-04-19T01:45:42.8373794Z 	at io.debezium.connector.sqlserver.SqlServerConnectorIT.excludeColumnWhenCaptureInstanceExcludesColumns(SqlServerConnectorIT.java:1667)
...
2021-04-19T02:02:32.3740628Z [ERROR] Tests run: 12, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 544.923 s <<< FAILURE! - in io.debezium.connector.sqlserver.SqlServerChangeTableSetIT
2021-04-19T02:02:32.3744118Z [ERROR] addColumnToTableWithParallelWrites(io.debezium.connector.sqlserver.SqlServerChangeTableSetIT)  Time elapsed: 75.145 s  <<< FAILURE!
2021-04-19T02:02:32.3746153Z java.lang.AssertionError: actual value:<0> should be greater than:<0>
2021-04-19T02:02:32.3749506Z 	at io.debezium.connector.sqlserver.SqlServerChangeTableSetIT.lambda$addColumnToTableWithParallelWrites$21(SqlServerChangeTableSetIT.java:523)
2021-04-19T02:02:32.3754251Z 	at io.debezium.connector.sqlserver.SqlServerChangeTableSetIT.addColumnToTableWithParallelWrites(SqlServerChangeTableSetIT.java:461)
...
2021-04-19T02:15:29.2667067Z [ERROR] Failures: 
2021-04-19T02:15:29.2669613Z [ERROR]   SqlServerChangeTableSetIT.addColumnToTableWithParallelWrites:461->lambda$addColumnToTableWithParallelWrites$21:523 actual value:<0> should be greater than:<0>
2021-04-19T02:15:29.2673642Z [ERROR]   SqlServerConnectorIT.excludeColumnWhenCaptureInstanceExcludesColumns:1667->lambda$excludeColumnWhenCaptureInstanceExcludesColumns$60:1680 expecting actual value not to be null

@morozov
Copy link
Author

morozov commented Apr 19, 2021 •
edited

The second failing test fails inconsistently. It fails because out of the four records which consumeRecordsByTopic is expected to return, it returns two:
Screen Shot 2021-04-18 at 7 57 20 PM

Full log: 
/Users/smorozov/Library/Java/JavaVirtualMachines/corretto-11.0.10/Contents/Home/bin/java -ea -Djava.awt.headless=true -Ddatabase.port=1433 -Ddatabase.user=sa -Ddatabase.password=Password! -DskipLongRunningTests=true -Didea.test.cyclic.buffer.size=1048576 -javaagent:/Applications/IntelliJ IDEA 2021.1 EAP.app/Contents/lib/idea_rt.jar=65446:/Applications/IntelliJ IDEA 2021.1 EAP.app/Contents/bin -Dfile.encoding=UTF-8 -classpath /Applications/IntelliJ IDEA 2021.1 EAP.app/Contents/lib/idea_rt.jar:/Applications/IntelliJ IDEA 2021.1 EAP.app/Contents/plugins/junit/lib/junit5-rt.jar:/Applications/IntelliJ IDEA 2021.1 EAP.app/Contents/plugins/junit/lib/junit-rt.jar:/Users/smorozov/Projects/debezium/debezium-connector-sqlserver/target/test-classes:/Users/smorozov/Projects/debezium/debezium-connector-sqlserver/target/classes:/Users/smorozov/Projects/debezium/debezium-core/target/classes:/Users/smorozov/Projects/debezium/debezium-api/target/classes:/Users/smorozov/.m2/repository/com/fasterxml/jackson/core/jackson-core/2.10.2/jackson-core-2.10.2.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.10.2/jackson-databind-2.10.2.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.10.2/jackson-annotations-2.10.2.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jsr310/2.10.2/jackson-datatype-jsr310-2.10.2.jar:/Users/smorozov/.m2/repository/org/reflections/reflections/0.9.12/reflections-0.9.12.jar:/Users/smorozov/.m2/repository/org/javassist/javassist/3.26.0-GA/javassist-3.26.0-GA.jar:/Users/smorozov/.m2/repository/com/google/guava/guava/30.0-jre/guava-30.0-jre.jar:/Users/smorozov/.m2/repository/com/google/guava/failureaccess/1.0.1/failureaccess-1.0.1.jar:/Users/smorozov/.m2/repository/com/google/guava/listenablefuture/9999.0-empty-to-avoid-conflict-with-guava/listenablefuture-9999.0-empty-to-avoid-conflict-with-guava.jar:/Users/smorozov/.m2/repository/com/microsoft/sqlserver/mssql-jdbc/7.2.2.jre8/mssql-jdbc-7.2.2.jre8.jar:/Users/smorozov/.m2/repository/org/apache/kafka/connect-api/2.6.1/connect-api-2.6.1.jar:/Users/smorozov/.m2/repository/org/apache/kafka/kafka-clients/2.6.1/kafka-clients-2.6.1.jar:/Users/smorozov/.m2/repository/com/github/luben/zstd-jni/1.4.4-7/zstd-jni-1.4.4-7.jar:/Users/smorozov/.m2/repository/org/lz4/lz4-java/1.7.1/lz4-java-1.7.1.jar:/Users/smorozov/.m2/repository/org/xerial/snappy/snappy-java/1.1.7.3/snappy-java-1.1.7.3.jar:/Users/smorozov/.m2/repository/javax/ws/rs/javax.ws.rs-api/2.1.1/javax.ws.rs-api-2.1.1.jar:/Users/smorozov/.m2/repository/org/slf4j/slf4j-api/1.7.30/slf4j-api-1.7.30.jar:/Users/smorozov/Projects/debezium/debezium-embedded/target/test-classes:/Users/smorozov/.m2/repository/org/apache/kafka/connect-runtime/2.6.1/connect-runtime-2.6.1.jar:/Users/smorozov/.m2/repository/org/apache/kafka/kafka-tools/2.6.1/kafka-tools-2.6.1.jar:/Users/smorozov/.m2/repository/org/apache/kafka/kafka-log4j-appender/2.6.1/kafka-log4j-appender-2.6.1.jar:/Users/smorozov/.m2/repository/net/sourceforge/argparse4j/argparse4j/0.7.0/argparse4j-0.7.0.jar:/Users/smorozov/.m2/repository/org/apache/kafka/connect-transforms/2.6.1/connect-transforms-2.6.1.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/jaxrs/jackson-jaxrs-json-provider/2.10.2/jackson-jaxrs-json-provider-2.10.2.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/jaxrs/jackson-jaxrs-base/2.10.2/jackson-jaxrs-base-2.10.2.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/module/jackson-module-jaxb-annotations/2.10.2/jackson-module-jaxb-annotations-2.10.2.jar:/Users/smorozov/.m2/repository/jakarta/xml/bind/jakarta.xml.bind-api/2.3.2/jakarta.xml.bind-api-2.3.2.jar:/Users/smorozov/.m2/repository/jakarta/activation/jakarta.activation-api/1.2.1/jakarta.activation-api-1.2.1.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/containers/jersey-container-servlet/2.31/jersey-container-servlet-2.31.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/containers/jersey-container-servlet-core/2.31/jersey-container-servlet-core-2.31.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/core/jersey-server/2.31/jersey-server-2.31.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/core/jersey-client/2.31/jersey-client-2.31.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/media/jersey-media-jaxb/2.31/jersey-media-jaxb-2.31.jar:/Users/smorozov/.m2/repository/jakarta/validation/jakarta.validation-api/2.0.2/jakarta.validation-api-2.0.2.jar:/Users/smorozov/.m2/repository/jakarta/ws/rs/jakarta.ws.rs-api/2.1.6/jakarta.ws.rs-api-2.1.6.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/inject/jersey-hk2/2.31/jersey-hk2-2.31.jar:/Users/smorozov/.m2/repository/org/glassfish/hk2/hk2-locator/2.6.1/hk2-locator-2.6.1.jar:/Users/smorozov/.m2/repository/org/glassfish/hk2/external/aopalliance-repackaged/2.6.1/aopalliance-repackaged-2.6.1.jar:/Users/smorozov/.m2/repository/org/glassfish/hk2/hk2-api/2.6.1/hk2-api-2.6.1.jar:/Users/smorozov/.m2/repository/org/glassfish/hk2/hk2-utils/2.6.1/hk2-utils-2.6.1.jar:/Users/smorozov/.m2/repository/javax/xml/bind/jaxb-api/2.3.1/jaxb-api-2.3.1.jar:/Users/smorozov/.m2/repository/javax/activation/javax.activation-api/1.2.0/javax.activation-api-1.2.0.jar:/Users/smorozov/.m2/repository/javax/activation/activation/1.1.1/activation-1.1.1.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-server/9.4.33.v20201020/jetty-server-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/javax/servlet/javax.servlet-api/3.1.0/javax.servlet-api-3.1.0.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-http/9.4.33.v20201020/jetty-http-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-io/9.4.33.v20201020/jetty-io-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-servlet/9.4.33.v20201020/jetty-servlet-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-security/9.4.33.v20201020/jetty-security-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-servlets/9.4.33.v20201020/jetty-servlets-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-continuation/9.4.33.v20201020/jetty-continuation-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-util/9.4.33.v20201020/jetty-util-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/eclipse/jetty/jetty-client/9.4.33.v20201020/jetty-client-9.4.33.v20201020.jar:/Users/smorozov/.m2/repository/org/apache/maven/maven-artifact/3.6.3/maven-artifact-3.6.3.jar:/Users/smorozov/.m2/repository/org/codehaus/plexus/plexus-utils/3.2.1/plexus-utils-3.2.1.jar:/Users/smorozov/.m2/repository/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.jar:/Users/smorozov/.m2/repository/org/apache/kafka/connect-json/2.6.1/connect-json-2.6.1.jar:/Users/smorozov/.m2/repository/com/fasterxml/jackson/datatype/jackson-datatype-jdk8/2.10.2/jackson-datatype-jdk8-2.10.2.jar:/Users/smorozov/.m2/repository/org/apache/kafka/connect-file/2.6.1/connect-file-2.6.1.jar:/Users/smorozov/Projects/debezium/debezium-core/target/test-classes:/Users/smorozov/Projects/debezium/debezium-embedded/target/classes:/Users/smorozov/.m2/repository/org/slf4j/slf4j-log4j12/1.7.30/slf4j-log4j12-1.7.30.jar:/Users/smorozov/.m2/repository/log4j/log4j/1.2.17/log4j-1.2.17.jar:/Users/smorozov/.m2/repository/junit/junit/4.13.1/junit-4.13.1.jar:/Users/smorozov/.m2/repository/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar:/Users/smorozov/.m2/repository/org/awaitility/awaitility/4.0.1/awaitility-4.0.1.jar:/Users/smorozov/.m2/repository/org/hamcrest/hamcrest/2.1/hamcrest-2.1.jar:/Users/smorozov/.m2/repository/org/easytesting/fest-assert/1.4/fest-assert-1.4.jar:/Users/smorozov/.m2/repository/org/easytesting/fest-util/1.1.6/fest-util-1.1.6.jar:/Users/smorozov/.m2/repository/io/confluent/kafka-connect-avro-converter/5.5.1/kafka-connect-avro-converter-5.5.1.jar:/Users/smorozov/.m2/repository/org/apache/avro/avro/1.9.2/avro-1.9.2.jar:/Users/smorozov/.m2/repository/org/apache/commons/commons-compress/1.19/commons-compress-1.19.jar:/Users/smorozov/.m2/repository/io/confluent/kafka-avro-serializer/5.5.1/kafka-avro-serializer-5.5.1.jar:/Users/smorozov/.m2/repository/io/confluent/kafka-schema-serializer/5.5.1/kafka-schema-serializer-5.5.1.jar:/Users/smorozov/.m2/repository/io/confluent/kafka-schema-registry-client/5.5.1/kafka-schema-registry-client-5.5.1.jar:/Users/smorozov/.m2/repository/org/glassfish/jersey/core/jersey-common/2.30/jersey-common-2.30.jar:/Users/smorozov/.m2/repository/jakarta/annotation/jakarta.annotation-api/1.3.5/jakarta.annotation-api-1.3.5.jar:/Users/smorozov/.m2/repository/org/glassfish/hk2/external/jakarta.inject/2.6.1/jakarta.inject-2.6.1.jar:/Users/smorozov/.m2/repository/org/glassfish/hk2/osgi-resource-locator/1.0.3/osgi-resource-locator-1.0.3.jar:/Users/smorozov/.m2/repository/com/sun/activation/jakarta.activation/1.2.1/jakarta.activation-1.2.1.jar:/Users/smorozov/.m2/repository/io/swagger/swagger-annotations/1.6.0/swagger-annotations-1.6.0.jar:/Users/smorozov/.m2/repository/io/confluent/kafka-connect-avro-data/5.5.1/kafka-connect-avro-data-5.5.1.jar:/Users/smorozov/.m2/repository/io/confluent/common-config/5.5.1/common-config-5.5.1.jar:/Users/smorozov/.m2/repository/io/confluent/common-utils/5.5.1/common-utils-5.5.1.jar com.intellij.rt.junit.JUnitStarter -ideVersion5 -junit4 io.debezium.connector.sqlserver.SqlServerConnectorIT,excludeColumnWhenCaptureInstanceExcludesColumns
2021-04-18 19:53:34,383 INFO   ||  Starting test io.debezium.connector.sqlserver.SqlServerConnectorIT#excludeColumnWhenCaptureInstanceExcludesColumns   [io.debezium.connector.sqlserver.SqlServerConnectorIT]
2021-04-18 19:53:38,179 INFO   SqlServerConnectorIT||test  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
2021-04-18 19:53:52,686 INFO   SqlServerConnectorIT||test  Worker configuration property 'internal.key.converter' is deprecated and may be removed in an upcoming release. The specified value 'org.apache.kafka.connect.json.JsonConverter' matches the default, so this property can be safely removed from the worker configuration.   [org.apache.kafka.connect.runtime.WorkerConfig]
2021-04-18 19:53:52,687 INFO   SqlServerConnectorIT||test  Worker configuration property 'internal.value.converter' is deprecated and may be removed in an upcoming release. The specified value 'org.apache.kafka.connect.json.JsonConverter' matches the default, so this property can be safely removed from the worker configuration.   [org.apache.kafka.connect.runtime.WorkerConfig]
2021-04-18 19:53:52,687 WARN   SqlServerConnectorIT||test  Variables cannot be used in the 'plugin.path' property, since the property is used by plugin scanning before the config providers that replace the variables are initialized. The raw value 'null' was used for plugin scanning, as opposed to the transformed value 'null', and this may cause unexpected results.   [org.apache.kafka.connect.runtime.WorkerConfig]
2021-04-18 19:53:52,695 INFO   SqlServerConnectorIT||engine  Starting FileOffsetBackingStore with file /Users/smorozov/Projects/debezium/debezium-connector-sqlserver/target/data/file-connector-offsets.txt   [org.apache.kafka.connect.storage.FileOffsetBackingStore]
2021-04-18 19:53:52,716 INFO   SqlServerConnectorIT||engine  Starting SqlServerConnectorTask with configuration:   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     connector.class = io.debezium.connector.sqlserver.SqlServerConnector   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.history.file.filename = /Users/smorozov/Projects/debezium/debezium-connector-sqlserver/target/data/file-db-history-connect.txt   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.user = sa   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.server.name = server1   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.port = 1433   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     include.schema.changes = false   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     offset.flush.interval.ms = 0   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     task.database.dbnames = testdb1,testdb2   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.dbnames = testdb1,testdb2   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     offset.storage.file.filename = /Users/smorozov/Projects/debezium/debezium-connector-sqlserver/target/data/file-connector-offsets.txt   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.hostname = localhost   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,717 INFO   SqlServerConnectorIT||engine     database.password = ********   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,718 INFO   SqlServerConnectorIT||engine     name = testing-connector   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,718 INFO   SqlServerConnectorIT||engine     database.history = io.debezium.relational.history.FileDatabaseHistory   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:52,718 INFO   SqlServerConnectorIT||engine     snapshot.mode = schema_only   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:53:53,023 INFO   SqlServerConnectorIT||engine  Requested thread factory for connector SqlServerConnector, id = server1 named = change-event-source-coordinator   [io.debezium.util.Threads]
2021-04-18 19:53:53,027 INFO   SqlServerConnectorIT||engine  Creating thread debezium-sqlserverconnector-server1-change-event-source-coordinator   [io.debezium.util.Threads]
2021-04-18 19:53:53,031 INFO   SqlServerConnectorIT||engine  Metrics registered   [io.debezium.pipeline.ChangeEventSourceCoordinator]
2021-04-18 19:53:53,031 INFO   SqlServerConnectorIT||engine  Context created   [io.debezium.pipeline.ChangeEventSourceCoordinator]
2021-04-18 19:53:53,037 INFO   SqlServerConnectorIT||engine  No previous offset has been found   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,037 INFO   SqlServerConnectorIT||engine  According to the connector configuration only schema will be snapshotted   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,038 INFO   SqlServerConnectorIT||engine  Snapshot step 1 - Preparing   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,038 INFO   SqlServerConnectorIT||engine  Snapshot step 2 - Determining captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,130 INFO   SqlServerConnectorIT||engine  Snapshot step 3 - Locking captured tables [testDB1.dbo.excluded_column_table_a, testDB1.dbo.tablea, testDB1.dbo.tableb]   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,130 INFO   SqlServerConnectorIT||engine  Setting locking timeout to 10 s   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,138 INFO   SqlServerConnectorIT||engine  Executing schema locking   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,139 INFO   SqlServerConnectorIT||engine  Locking table testDB1.dbo.excluded_column_table_a   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,141 INFO   SqlServerConnectorIT||engine  Locking table testDB1.dbo.tablea   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,145 INFO   SqlServerConnectorIT||engine  Locking table testDB1.dbo.tableb   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,148 INFO   SqlServerConnectorIT||engine  Snapshot step 4 - Determining snapshot offset   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,157 INFO   SqlServerConnectorIT||engine  Snapshot step 5 - Reading structure of captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,158 INFO   SqlServerConnectorIT||engine  Reading structure of schema 'testDB1'   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,511 INFO   SqlServerConnectorIT||engine  Snapshot step 6 - Persisting schema history   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,515 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB1, schema=dbo, ddl=null, tables=[columns: {
  id int(10, 0) NOT NULL
  name varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=CREATE]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:53,544 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB1, schema=dbo, ddl=null, tables=[columns: {
  id int(10, 0) NOT NULL
  cola varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=CREATE]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:53,545 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB1, schema=dbo, ddl=null, tables=[columns: {
  id int(10, 0) NOT NULL
  colb varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=CREATE]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:53,550 INFO   SqlServerConnectorIT||engine  Schema locks released.   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,550 INFO   SqlServerConnectorIT||engine  Snapshot step 7 - Skipping snapshotting of data   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,554 INFO   SqlServerConnectorIT||engine  Snapshot - Final stage   [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
2021-04-18 19:53:53,556 INFO   SqlServerConnectorIT||engine  Removing locking timeout   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,559 INFO   SqlServerConnectorIT||engine  Snapshot ended with SnapshotResult [status=COMPLETED, offset=SqlServerOffsetContext [sourceInfoSchema=Schema{io.debezium.connector.sqlserver.Source:STRUCT}, sourceInfo=SourceInfo [serverName=server1, changeLsn=NULL, commitLsn=00000026:00000c58:001a, eventSerialNo=null, snapshot=FALSE, sourceTime=2021-04-19T02:53:53.545Z], partition={server=server1, database=testDB1}, snapshotCompleted=true, eventSerialNo=1]]   [io.debezium.pipeline.ChangeEventSourceCoordinator]
2021-04-18 19:53:53,560 INFO   SqlServerConnectorIT||engine  No previous offset has been found   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,560 INFO   SqlServerConnectorIT||engine  According to the connector configuration only schema will be snapshotted   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,560 INFO   SqlServerConnectorIT||engine  Snapshot step 1 - Preparing   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,560 INFO   SqlServerConnectorIT||engine  Snapshot step 2 - Determining captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,623 INFO   SqlServerConnectorIT||engine  Snapshot step 3 - Locking captured tables [testDB2.dbo.excluded_column_table_a, testDB2.dbo.tablea, testDB2.dbo.tableb]   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,623 INFO   SqlServerConnectorIT||engine  Setting locking timeout to 10 s   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,630 INFO   SqlServerConnectorIT||engine  Executing schema locking   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,631 INFO   SqlServerConnectorIT||engine  Locking table testDB2.dbo.excluded_column_table_a   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,633 INFO   SqlServerConnectorIT||engine  Locking table testDB2.dbo.tablea   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,636 INFO   SqlServerConnectorIT||engine  Locking table testDB2.dbo.tableb   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,638 INFO   SqlServerConnectorIT||engine  Snapshot step 4 - Determining snapshot offset   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,641 INFO   SqlServerConnectorIT||engine  Snapshot step 5 - Reading structure of captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,641 INFO   SqlServerConnectorIT||engine  Reading structure of schema 'testDB2'   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,981 INFO   SqlServerConnectorIT||engine  Snapshot step 6 - Persisting schema history   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,981 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB2, schema=dbo, ddl=null, tables=[columns: {
  id int(10, 0) NOT NULL
  name varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=CREATE]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:53,983 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB2, schema=dbo, ddl=null, tables=[columns: {
  id int(10, 0) NOT NULL
  cola varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=CREATE]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:53,984 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB2, schema=dbo, ddl=null, tables=[columns: {
  id int(10, 0) NOT NULL
  colb varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=CREATE]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:53,991 INFO   SqlServerConnectorIT||engine  Schema locks released.   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:53,991 INFO   SqlServerConnectorIT||engine  Snapshot step 7 - Skipping snapshotting of data   [io.debezium.relational.RelationalSnapshotChangeEventSource]
2021-04-18 19:53:53,994 INFO   SqlServerConnectorIT||engine  Snapshot - Final stage   [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
2021-04-18 19:53:53,997 INFO   SqlServerConnectorIT||engine  Removing locking timeout   [io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource]
2021-04-18 19:53:54,003 INFO   SqlServerConnectorIT||engine  Snapshot ended with SnapshotResult [status=COMPLETED, offset=SqlServerOffsetContext [sourceInfoSchema=Schema{io.debezium.connector.sqlserver.Source:STRUCT}, sourceInfo=SourceInfo [serverName=server1, changeLsn=NULL, commitLsn=00000027:00000540:0003, eventSerialNo=null, snapshot=FALSE, sourceTime=2021-04-19T02:53:53.984Z], partition={server=server1, database=testDB2}, snapshotCompleted=true, eventSerialNo=1]]   [io.debezium.pipeline.ChangeEventSourceCoordinator]
2021-04-18 19:53:54,007 INFO   SqlServerConnectorIT||engine  Connected metrics set to 'true'   [io.debezium.pipeline.metrics.StreamingChangeEventSourceMetrics]
2021-04-18 19:53:54,007 INFO   SqlServerConnectorIT||engine  Starting streaming   [io.debezium.pipeline.ChangeEventSourceCoordinator]
2021-04-18 19:53:54,026 INFO   SqlServerConnectorIT||engine  Last position recorded in offsets is 00000026:00000c58:001a(NULL)[1]   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:54,036 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:54,058 INFO   SqlServerConnectorIT||engine  Last position recorded in offsets is 00000027:00000540:0003(NULL)[1]   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:54,066 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:54,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:54,544 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:55,027 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:55,047 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:55,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:55,542 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:56,025 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:56,048 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:56,524 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:56,541 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,047 INFO   SqlServerConnectorIT||engine  Schema will be changed for Capture instance "dbo_excluded_column_table_a" [sourceTableId=testDB1.dbo.excluded_column_table_a, changeTableId=testDB1.cdc.dbo_excluded_column_table_a_CT, startLsn=00000026:00000ce8:003a, changeTableObjectId=1189579276, stopLsn=NULL]   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,088 INFO   SqlServerConnectorIT||engine  Migrating schema to Capture instance "dbo_excluded_column_table_a" [sourceTableId=testDB1.dbo.excluded_column_table_a, changeTableId=testDB1.cdc.dbo_excluded_column_table_a_CT, startLsn=00000026:00000ce8:003a, changeTableObjectId=1189579276, stopLsn=NULL]   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,111 DEBUG  SqlServerConnectorIT||engine  Applying schema change event SchemaChangeEvent [database=testDB1, schema=dbo, ddl=N/A, tables=[columns: {
  id int(10, 0) NOT NULL
  name varchar(30) DEFAULT VALUE NULL
}
primary key: [id]
default charset: null
], type=ALTER]   [io.debezium.connector.sqlserver.SqlServerDatabaseSchema]
2021-04-18 19:53:57,113 INFO   SqlServerConnectorIT||engine  Already applied 7 database changes   [io.debezium.relational.history.DatabaseHistoryMetrics]
2021-04-18 19:53:57,181 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,199 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,217 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,526 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:57,552 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:58,023 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:58,046 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:58,524 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:58,541 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:59,023 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:59,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:59,524 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:53:59,541 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:00,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:00,042 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:00,527 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:00,548 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:01,023 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:01,040 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:01,523 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:01,540 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:02,025 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:02,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:02,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:02,543 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:03,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:03,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:03,523 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:03,540 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:04,023 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:04,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:04,523 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:04,540 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:05,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:05,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:05,523 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:05,540 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:06,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:06,042 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:06,523 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:06,540 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:07,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:07,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:07,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:07,542 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:08,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:08,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:08,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:08,543 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:09,025 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:09,042 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:09,524 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:09,542 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:10,025 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:10,042 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:10,524 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:10,541 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:11,024 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:11,041 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:11,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:11,542 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:12,025 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:12,042 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:12,525 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:12,541 DEBUG  SqlServerConnectorIT||engine  No change in the database   [io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource]
2021-04-18 19:54:12,666 INFO   SqlServerConnectorIT||test  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
2021-04-18 19:54:12,666 INFO   SqlServerConnectorIT||test  Stopping the connector   [io.debezium.connector.sqlserver.SqlServerConnectorIT]
2021-04-18 19:54:12,666 INFO   SqlServerConnectorIT||test  Stopping the engine   [io.debezium.connector.sqlserver.SqlServerConnectorIT]
2021-04-18 19:54:12,666 INFO   SqlServerConnectorIT||test  Stopping the embedded engine   [io.debezium.embedded.EmbeddedEngine]
2021-04-18 19:54:12,666 INFO   SqlServerConnectorIT||test  Waiting for PT5M for connector to stop   [io.debezium.embedded.EmbeddedEngine]
2021-04-18 19:54:13,008 INFO   SqlServerConnectorIT||engine  Stopping down connector   [io.debezium.connector.common.BaseSourceTask]
2021-04-18 19:54:13,021 INFO   SqlServerConnectorIT||engine  Finished streaming   [io.debezium.pipeline.ChangeEventSourceCoordinator]
2021-04-18 19:54:13,021 INFO   SqlServerConnectorIT||engine  Connected metrics set to 'false'   [io.debezium.pipeline.metrics.StreamingChangeEventSourceMetrics]
2021-04-18 19:54:13,024 INFO   SqlServerConnectorIT||engine  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
2021-04-18 19:54:13,025 INFO   SqlServerConnectorIT||engine  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
2021-04-18 19:54:13,026 INFO   SqlServerConnectorIT||engine  Stopped FileOffsetBackingStore   [org.apache.kafka.connect.storage.FileOffsetBackingStore]
2021-04-18 19:54:13,027 INFO   SqlServerConnectorIT||engine  Connector 'io.debezium.connector.sqlserver.SqlServerConnector' completed normally.   [io.debezium.connector.sqlserver.SqlServerConnectorIT]
2021-04-18 19:54:13,027 INFO   SqlServerConnectorIT||test  Interrupting the engine   [io.debezium.connector.sqlserver.SqlServerConnectorIT]
2021-04-18 19:54:13,030 INFO   SqlServerConnectorIT||test  Test io.debezium.connector.sqlserver.SqlServerConnectorIT#excludeColumnWhenCaptureInstanceExcludesColumns failed   [io.debezium.connector.sqlserver.SqlServerConnectorIT]

java.lang.AssertionError: expecting actual value not to be null

	at org.fest.assertions.Fail.failure(Fail.java:228)
	at org.fest.assertions.Fail.fail(Fail.java:167)
	at org.fest.assertions.Fail.failIfActualIsNull(Fail.java:100)
	at org.fest.assertions.GenericAssert.isNotNull(GenericAssert.java:238)
	at org.fest.assertions.GroupAssert.hasSize(GroupAssert.java:85)
	at io.debezium.connector.sqlserver.SqlServerConnectorIT.lambda$excludeColumnWhenCaptureInstanceExcludesColumns$60(SqlServerConnectorIT.java:1680)
	at io.debezium.connector.sqlserver.util.TestHelper$ThrowingConsumer.accept(TestHelper.java:135)
	at com.google.common.collect.ImmutableList.forEach(ImmutableList.java:405)
	at io.debezium.connector.sqlserver.util.TestHelper.forEachDatabase(TestHelper.java:146)
	at io.debezium.connector.sqlserver.SqlServerConnectorIT.excludeColumnWhenCaptureInstanceExcludesColumns(SqlServerConnectorIT.java:1667)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	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.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:61)
	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.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69)
	at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33)
	at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:221)
	at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:54)

Process finished with exit code 255

@morozov
Copy link
Author

morozov commented Apr 19, 2021 •
edited

Actually, the above failure might be solved by #42. Currently, metrics are shared across all partitions, so waitForSnapshotToBeCompleted() is returned as soon as the first database is snapshotted.

@mikekamornikov
Copy link

@morozov Regarding "2." does it mean we execute streaming logic even in STREAMING_NOT_ENABLED case? Is it a bug?

@morozov
Copy link
Author

morozov commented Apr 19, 2021

@morozov Regarding "2." does it mean we execute streaming logic even in STREAMING_NOT_ENABLED case? Is it a bug?

By "2.", do you mean

The current logic assumes that the events have been streamed unless the object is in one of the blacklisted states.

I don't think so. The result of eventsStreamed() is primarily intended to be used to decide whether the task needs to sleep before another iteration over the list of partitions during streaming.

@morozov morozov merged commit e9ae1a3 into sugarcrm:DBZ-2975 Apr 19, 2021
@morozov morozov deleted the CXP-918 branch April 19, 2021 15:30
This was referenced Apr 19, 2021
Closed
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@mikekamornikov mikekamornikov mikekamornikov approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

None yet
2 participants
@morozov @mikekamornikov