2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.access_token: is missing but it is required, $.refresh_token: is missing but it is required 2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.password: object found, string expected 2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.part_size: is not defined in the schema and the schema does not allow additional properties, $.encryption: is not defined in the schema and the schema does not allow additional properties, $.access_key_id: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_name: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_region: is not defined in the schema and the schema does not allow additional properties, $.secret_access_key: is not defined in the schema and the schema does not allow additional properties, $.purge_staging_data: is not defined in the schema and the schema does not allow additional properties, $.method: does not have a value in the enumeration [Standard] 2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.part_size: is not defined in the schema and the schema does not allow additional properties, $.encryption: is not defined in the schema and the schema does not allow additional properties, $.access_key_id: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_name: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_region: is not defined in the schema and the schema does not allow additional properties, $.secret_access_key: is not defined in the schema and the schema does not allow additional properties, $.purge_staging_data: is not defined in the schema and the schema does not allow additional properties, $.method: does not have a value in the enumeration [Internal Staging] 2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.access_key_id: object found, string expected, $.secret_access_key: object found, string expected 2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.project_id: is missing but it is required, $.bucket_name: is missing but it is required, $.credentials_json: is missing but it is required, $.part_size: is not defined in the schema and the schema does not allow additional properties, $.encryption: is not defined in the schema and the schema does not allow additional properties, $.access_key_id: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_name: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_region: is not defined in the schema and the schema does not allow additional properties, $.secret_access_key: is not defined in the schema and the schema does not allow additional properties, $.purge_staging_data: is not defined in the schema and the schema does not allow additional properties, $.method: does not have a value in the enumeration [GCS Staging] 2022-06-13 23:33:52 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $.azure_blob_storage_account_name: is missing but it is required, $.azure_blob_storage_container_name: is missing but it is required, $.azure_blob_storage_sas_token: is missing but it is required, $.part_size: is not defined in the schema and the schema does not allow additional properties, $.encryption: is not defined in the schema and the schema does not allow additional properties, $.access_key_id: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_name: is not defined in the schema and the schema does not allow additional properties, $.s3_bucket_region: is not defined in the schema and the schema does not allow additional properties, $.secret_access_key: is not defined in the schema and the schema does not allow additional properties, $.purge_staging_data: is not defined in the schema and the schema does not allow additional properties, $.method: does not have a value in the enumeration [Azure Blob Staging] 2022-06-13 23:33:53 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/26613/0/logs.log 2022-06-13 23:33:53 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.13-alpha 2022-06-13 23:33:53 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if danieldiamond/source-mysql:0.1.0 exists... 2022-06-13 23:33:53 INFO i.a.c.i.LineGobbler(voidCall):82 - danieldiamond/source-mysql:0.1.0 was found locally. 2022-06-13 23:33:53 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 26613 2022-06-13 23:33:53 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/26613/0 --log-driver none --name source-mysql-check-26613-0-sgtak --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=danieldiamond/source-mysql:0.1.0 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.39.13-alpha -e WORKER_JOB_ID=26613 danieldiamond/source-mysql:0.1.0 check --config source_config.json 2022-06-13 23:33:56 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Class path contains multiple SLF4J bindings. 2022-06-13 23:33:56 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:33:56 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.30.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:33:56 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2022-06-13 23:33:57 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 INFO i.a.i.s.m.MySqlSource(main):211 - starting source: class io.airbyte.integrations.source.mysql.MySqlSource 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {check=null, config=source_config.json} 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Running integration: io.airbyte.integrations.base.ssh.SshWrappedSource 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 INFO i.a.i.b.IntegrationRunner(runInternal):124 - Command: CHECK 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 INFO i.a.i.b.IntegrationRunner(runInternal):125 - Integration config: IntegrationConfig{command=CHECK, configPath='source_config.json', catalogPath='null', statePath='null'} 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:33:57 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:57 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:33:58 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:58 INFO i.a.i.b.s.SshTunnel(getInstance):170 - Starting connection with method: NO_TUNNEL 2022-06-13 23:33:58 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:58 INFO c.z.h.HikariDataSource():80 - HikariPool-1 - Starting... 2022-06-13 23:33:58 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:58 INFO c.z.h.HikariDataSource():82 - HikariPool-1 - Start completed. 2022-06-13 23:33:58 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:58 INFO i.a.i.s.j.AbstractJdbcSource(lambda$getCheckOperations$1):93 - Attempting to get metadata from the database to see if we can connect. 2022-06-13 23:33:58 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:58 INFO c.z.h.HikariDataSource(close):350 - HikariPool-1 - Shutdown initiated... 2022-06-13 23:33:58 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:33:58 INFO c.z.h.HikariDataSource(close):352 - HikariPool-1 - Shutdown completed. 2022-06-13 23:34:01 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling... 2022-06-13 23:34:01 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/26613/0/logs.log 2022-06-13 23:34:01 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.13-alpha 2022-06-13 23:34:01 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-snowflake:0.4.28 exists... 2022-06-13 23:34:01 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-snowflake:0.4.28 was found locally. 2022-06-13 23:34:01 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 26613 2022-06-13 23:34:01 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/26613/0 --log-driver none --name destination-snowflake-check-26613-0-mmhjf --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/destination-snowflake:0.4.28 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.39.13-alpha -e WORKER_JOB_ID=26613 airbyte/destination-snowflake:0.4.28 check --config source_config.json 2022-06-13 23:34:03 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Class path contains multiple SLF4J bindings. 2022-06-13 23:34:03 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:03 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:03 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Found binding in [jar:file:/airbyte/lib/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:03 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2022-06-13 23:34:03 ERROR i.a.c.i.LineGobbler(voidCall):82 - SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {check=null, config=source_config.json} 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Running integration: io.airbyte.integrations.destination.snowflake.SnowflakeDestination 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 INFO i.a.i.b.IntegrationRunner(runInternal):124 - Command: CHECK 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 INFO i.a.i.b.IntegrationRunner(runInternal):125 - Integration config: IntegrationConfig{command=CHECK, configPath='source_config.json', catalogPath='null', statePath='null'} 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 INFO i.a.i.d.j.c.SwitchingDestination(check):55 - Using destination type: COPY_S3 2022-06-13 23:34:04 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:04 INFO i.a.i.d.s.S3DestinationConfig(createS3Client):166 - Creating S3 client... 2022-06-13 23:34:05 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:05 INFO c.z.h.HikariDataSource(getConnection):110 - HikariPool-1 - Starting... 2022-06-13 23:34:06 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:06 INFO c.z.h.p.HikariPool(checkFailFast):565 - HikariPool-1 - Added connection net.snowflake.client.jdbc.SnowflakeConnectionV1@483f286e 2022-06-13 23:34:06 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:06 INFO c.z.h.HikariDataSource(getConnection):123 - HikariPool-1 - Start completed. 2022-06-13 23:34:06 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:06 INFO i.a.d.j.DefaultJdbcDatabase(lambda$unsafeQuery$1):105 - closing connection 2022-06-13 23:34:07 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:07 INFO i.a.i.d.s.S3StorageOperations(createBucketObjectIfNotExists):97 - Storage Object my-bucket/_ANALYTICS__AIRBYTE_CONNECTION_TEST_20A02BAD_FA3F_4F92_8027_6F32FBE49D77 does not exist in bucket; creating... 2022-06-13 23:34:07 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:07 INFO i.a.i.d.s.S3StorageOperations(createBucketObjectIfNotExists):99 - Storage Object my-bucket/_ANALYTICS__AIRBYTE_CONNECTION_TEST_20A02BAD_FA3F_4F92_8027_6F32FBE49D77 has been created in bucket. 2022-06-13 23:34:07 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:07 INFO i.a.i.d.s.S3StorageOperations(cleanUpObjects):281 - Deleting objects _ANALYTICS__AIRBYTE_CONNECTION_TEST_20A02BAD_FA3F_4F92_8027_6F32FBE49D77/ 2022-06-13 23:34:07 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:07 INFO i.a.i.d.s.S3StorageOperations(cleanUpBucketObject):270 - Storage bucket _ANALYTICS__AIRBYTE_CONNECTION_TEST_20A02BAD_FA3F_4F92_8027_6F32FBE49D77 has been cleaned-up (1 objects were deleted)... 2022-06-13 23:34:07 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:07 INFO c.z.h.HikariDataSource(close):350 - HikariPool-1 - Shutdown initiated... 2022-06-13 23:34:08 INFO i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$0):61 - 2022-06-13 23:34:08 INFO c.z.h.HikariDataSource(close):352 - HikariPool-1 - Shutdown completed. 2022-06-13 23:34:11 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling... 2022-06-13 23:34:11 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/26613/0/logs.log 2022-06-13 23:34:11 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.13-alpha 2022-06-13 23:34:11 INFO i.a.w.g.DefaultReplicationWorker(run):115 - start sync worker. job id: 26613 attempt id: 0 2022-06-13 23:34:11 INFO i.a.w.i.DefaultAirbyteDestination(start):69 - Running destination... 2022-06-13 23:34:11 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/destination-snowflake:0.4.28 exists... 2022-06-13 23:34:11 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/destination-snowflake:0.4.28 was found locally. 2022-06-13 23:34:11 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 26613 2022-06-13 23:34:11 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/26613/0 --log-driver none --name destination-snowflake-write-26613-0-bdiiw --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=airbyte/destination-snowflake:0.4.28 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.39.13-alpha -e WORKER_JOB_ID=26613 airbyte/destination-snowflake:0.4.28 write --config destination_config.json --catalog destination_catalog.json 2022-06-13 23:34:11 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if danieldiamond/source-mysql:0.1.0 exists... 2022-06-13 23:34:11 INFO i.a.c.i.LineGobbler(voidCall):82 - danieldiamond/source-mysql:0.1.0 was found locally. 2022-06-13 23:34:11 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 26613 2022-06-13 23:34:11 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/26613/0 --log-driver none --name source-mysql-read-26613-0-onwup --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_CONNECTOR_IMAGE=danieldiamond/source-mysql:0.1.0 -e WORKER_JOB_ATTEMPT=0 -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.39.13-alpha -e WORKER_JOB_ID=26613 danieldiamond/source-mysql:0.1.0 read --config source_config.json --catalog source_catalog.json 2022-06-13 23:34:11 INFO i.a.w.g.DefaultReplicationWorker(run):169 - Waiting for source and destination threads to complete. 2022-06-13 23:34:11 INFO i.a.w.g.DefaultReplicationWorker(lambda$getDestinationOutputRunnable$7):395 - Destination output thread started. 2022-06-13 23:34:11 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):298 - Replication thread started. 2022-06-13 23:34:14 destination > SLF4J: Class path contains multiple SLF4J bindings. 2022-06-13 23:34:14 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:14 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.25.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:14 destination > SLF4J: Found binding in [jar:file:/airbyte/lib/logback-classic-1.2.3.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:14 destination > SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2022-06-13 23:34:14 destination > SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] 2022-06-13 23:34:14 source > SLF4J: Class path contains multiple SLF4J bindings. 2022-06-13 23:34:14 source > SLF4J: Found binding in [jar:file:/airbyte/lib/log4j-slf4j-impl-2.17.1.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:14 source > SLF4J: Found binding in [jar:file:/airbyte/lib/slf4j-log4j12-1.7.30.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2022-06-13 23:34:14 source > SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2022-06-13 23:34:14 source > SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory] 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json} 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Running integration: io.airbyte.integrations.destination.snowflake.SnowflakeDestination 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationRunner(runInternal):124 - Command: WRITE 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationRunner(runInternal):125 - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'} 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 INFO i.a.i.s.m.MySqlSource(main):211 - starting source: class io.airbyte.integrations.source.mysql.MySqlSource 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 INFO i.a.i.d.j.c.SwitchingDestination(getConsumer):65 - Using destination type: COPY_S3 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationCliParser(parseOptions):118 - integration args: {read=null, catalog=source_catalog.json, config=source_config.json} 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationRunner(runInternal):123 - Running integration: io.airbyte.integrations.base.ssh.SshWrappedSource 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationRunner(runInternal):124 - Command: READ 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 INFO i.a.i.b.IntegrationRunner(runInternal):125 - Integration config: IntegrationConfig{command=READ, configPath='source_config.json', catalogPath='source_catalog.json', statePath='null'} 2022-06-13 23:34:15 destination > 2022-06-13 23:34:15 INFO i.a.i.d.s.S3DestinationConfig(createS3Client):166 - Creating S3 client... 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword order - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword examples - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword airbyte_secret - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:15 source > 2022-06-13 23:34:15 WARN c.n.s.JsonMetaSchema(newValidator):338 - Unknown keyword multiline - you should define your own Meta Schema. If the keyword is irrelevant for validation, just use a NonValidationKeyword 2022-06-13 23:34:16 source > 2022-06-13 23:34:16 INFO i.a.i.b.s.SshTunnel(getInstance):170 - Starting connection with method: NO_TUNNEL 2022-06-13 23:34:16 source > 2022-06-13 23:34:16 INFO i.a.i.s.r.CdcStateManager():26 - Initialized CDC state with: null ... ... 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - connector.class = io.debezium.connector.mysql.MySqlConnector 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - snapshot.locking.mode = none 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - max.queue.size = 81290 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - include.schema.changes = false 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - binary.handling.mode = base64 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - offset.storage.file.filename = /tmp/cdc-state-offset12349916628998844813/offset.dat 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - decimal.handling.mode = string 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - converters = boolean, datetime 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - datetime.type = io.airbyte.integrations.debezium.internals.MySQLConverter 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - database.history.file.filename = /tmp/cdc-db-history6674584482788468610/dbhistory.dat 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - database.user = analytics-airbyte ... 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - offset.storage = org.apache.kafka.connect.storage.FileOffsetBackingStore 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - boolean.type = io.debezium.connector.mysql.converters.TinyIntOneToBooleanConverter 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - offset.flush.timeout.ms = 60000 ... 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - database.port = 3306 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - offset.flush.interval.ms = 10000 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - max.request.size = 10485760 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - key.converter.schemas.enable = false ... 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - database.password = ******** ... 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - value.converter.schemas.enable = false 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - max.batch.size = 20480 ... 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - snapshot.mode = initial 2022-06-13 23:34:17 source > 2022-06-13 23:34:17 INFO i.d.c.c.BaseSourceTask(lambda$start$0):102 - database.history = io.airbyte.integrations.debezium.internals.FilteredFileDatabaseHistory ... .. ... 2022-06-13 23:34:19 destination > 2022-06-13 23:34:19 INFO i.a.i.d.r.SerializedBufferingStrategy(lambda$addRecord$0):55 - Starting a new buffer for stream mytable (current state: 0 bytes in 0 buffers) 2022-06-13 23:34:19 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 1000 (479 KB) 2022-06-13 23:34:19 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 2000 (959 KB) 2022-06-13 23:34:19 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 3000 (1 MB) 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 4000 (1 MB) 2022-06-13 23:34:20 source > 2022-06-13 23:34:19 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 10000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:00.569 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 5000 (2 MB) 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 6000 (2 MB) 2022-06-13 23:34:20 source > 2022-06-13 23:34:19 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 20000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:00.882 2022-06-13 23:34:20 source > 2022-06-13 23:34:20 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 30000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:01.009 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 7000 (3 MB) 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 8000 (3 MB) 2022-06-13 23:34:20 source > 2022-06-13 23:34:20 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 40000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:01.225 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 9000 (4 MB) 2022-06-13 23:34:20 source > 2022-06-13 23:34:20 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 50000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:01.468 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 10000 (4 MB) 2022-06-13 23:34:20 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 11000 (5 MB) 2022-06-13 23:34:21 source > 2022-06-13 23:34:20 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 60000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:01.622 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 12000 (5 MB) 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 13000 (6 MB) 2022-06-13 23:34:21 source > 2022-06-13 23:34:20 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 70000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:01.805 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 14000 (6 MB) 2022-06-13 23:34:21 source > 2022-06-13 23:34:21 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 80000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:01.978 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 15000 (7 MB) 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 16000 (7 MB) 2022-06-13 23:34:21 source > 2022-06-13 23:34:21 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 90000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:02.185 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 17000 (7 MB) 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 18000 (8 MB) 2022-06-13 23:34:21 source > 2022-06-13 23:34:21 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 100000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:02.348 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 19000 (8 MB) 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 20000 (9 MB) 2022-06-13 23:34:21 source > 2022-06-13 23:34:21 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 110000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:02.503 2022-06-13 23:34:21 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 21000 (9 MB) 2022-06-13 23:34:22 source > 2022-06-13 23:34:21 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 120000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:02.662 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 22000 (10 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 23000 (10 MB) 2022-06-13 23:34:22 source > 2022-06-13 23:34:21 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 130000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:02.842 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 24000 (11 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 25000 (11 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 26000 (12 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 27000 (12 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 28000 (13 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 29000 (13 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 30000 (14 MB) 2022-06-13 23:34:22 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 31000 (14 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 32000 (15 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 33000 (15 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 34000 (15 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 35000 (16 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 36000 (16 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 37000 (17 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 38000 (17 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 39000 (18 MB) 2022-06-13 23:34:23 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 40000 (18 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 41000 (19 MB) 2022-06-13 23:34:24 source > 2022-06-13 23:34:23 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 140000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:04.618 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 42000 (19 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 43000 (20 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 44000 (20 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 45000 (21 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 46000 (21 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 47000 (22 MB) 2022-06-13 23:34:24 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 48000 (22 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 49000 (23 MB) 2022-06-13 23:34:25 source > 2022-06-13 23:34:24 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 150000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:05.759 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 50000 (23 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 51000 (23 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 52000 (24 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 53000 (24 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 54000 (25 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 55000 (25 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 56000 (26 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 57000 (26 MB) 2022-06-13 23:34:25 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 58000 (27 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 59000 (27 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 60000 (28 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 61000 (28 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 62000 (29 MB) 2022-06-13 23:34:26 source > 2022-06-13 23:34:26 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 160000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:07.073 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 63000 (29 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 64000 (30 MB) 2022-06-13 23:34:26 source > 2022-06-13 23:34:26 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 170000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:07.235 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 65000 (30 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 66000 (31 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 67000 (31 MB) 2022-06-13 23:34:26 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 68000 (31 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 69000 (32 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 70000 (32 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 71000 (33 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 72000 (33 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 73000 (34 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 74000 (34 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 75000 (35 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 76000 (35 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 77000 (36 MB) 2022-06-13 23:34:27 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 78000 (36 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 79000 (37 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 80000 (37 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 81000 (38 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 82000 (38 MB) 2022-06-13 23:34:28 source > 2022-06-13 23:34:28 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 180000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:09.047 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 83000 (39 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 84000 (39 MB) 2022-06-13 23:34:28 source > 2022-06-13 23:34:28 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 190000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:09.177 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 85000 (40 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 86000 (40 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 87000 (40 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 88000 (41 MB) 2022-06-13 23:34:28 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 89000 (41 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 90000 (42 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 91000 (42 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 92000 (43 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 93000 (43 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 94000 (44 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 95000 (44 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 96000 (45 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 97000 (45 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 98000 (46 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 99000 (46 MB) 2022-06-13 23:34:29 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 100000 (47 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 101000 (47 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 102000 (48 MB) 2022-06-13 23:34:30 source > 2022-06-13 23:34:29 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 200000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:10.864 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 103000 (48 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 104000 (48 MB) 2022-06-13 23:34:30 source > 2022-06-13 23:34:30 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 210000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:11.034 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 105000 (49 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 106000 (49 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 107000 (50 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 108000 (50 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 109000 (51 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 110000 (51 MB) 2022-06-13 23:34:30 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 111000 (52 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 112000 (52 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 113000 (53 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 114000 (53 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 115000 (54 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 116000 (54 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 117000 (55 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 118000 (55 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 119000 (56 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 120000 (56 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 121000 (57 MB) 2022-06-13 23:34:31 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 122000 (57 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 123000 (57 MB) 2022-06-13 23:34:32 source > 2022-06-13 23:34:31 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 220000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:12.804 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 124000 (58 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 125000 (58 MB) 2022-06-13 23:34:32 source > 2022-06-13 23:34:32 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 230000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:12.954 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 126000 (59 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127000 (59 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 128000 (60 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 129000 (60 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 130000 (61 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 131000 (61 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 132000 (62 MB) 2022-06-13 23:34:32 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 133000 (62 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 134000 (63 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 135000 (63 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 136000 (64 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 137000 (64 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 138000 (65 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 139000 (65 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 140000 (65 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 141000 (66 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 142000 (66 MB) 2022-06-13 23:34:33 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 143000 (67 MB) 2022-06-13 23:34:34 source > 2022-06-13 23:34:33 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 240000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:14.579 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 144000 (67 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 145000 (68 MB) 2022-06-13 23:34:34 source > 2022-06-13 23:34:33 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 250000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:14.749 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 146000 (68 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 147000 (69 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 148000 (69 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 149000 (70 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 150000 (70 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 151000 (71 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 152000 (71 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 153000 (72 MB) 2022-06-13 23:34:34 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 154000 (72 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 155000 (73 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 156000 (73 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 157000 (74 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 158000 (74 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 159000 (74 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 160000 (75 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 161000 (75 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 162000 (76 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 163000 (76 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 164000 (77 MB) 2022-06-13 23:34:35 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 165000 (77 MB) 2022-06-13 23:34:36 source > 2022-06-13 23:34:35 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 260000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:16.592 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 166000 (78 MB) 2022-06-13 23:34:36 source > 2022-06-13 23:34:35 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 270000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:16.797 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 167000 (78 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 168000 (79 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 169000 (79 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 170000 (80 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 171000 (80 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 172000 (81 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 173000 (81 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 174000 (82 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 175000 (82 MB) 2022-06-13 23:34:36 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 176000 (82 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 177000 (83 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 178000 (83 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 179000 (84 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 180000 (84 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 181000 (85 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 182000 (85 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 183000 (86 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 184000 (86 MB) 2022-06-13 23:34:37 source > 2022-06-13 23:34:37 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 280000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:18.384 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 185000 (87 MB) 2022-06-13 23:34:37 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 186000 (87 MB) 2022-06-13 23:34:38 source > 2022-06-13 23:34:37 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 290000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:18.67 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 187000 (88 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 188000 (88 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 189000 (89 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 190000 (89 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 191000 (90 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 192000 (90 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 193000 (91 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 194000 (91 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 195000 (91 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 196000 (92 MB) 2022-06-13 23:34:38 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 197000 (92 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 198000 (93 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 199000 (93 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 200000 (94 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 201000 (94 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 202000 (95 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 203000 (95 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 204000 (96 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 205000 (96 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 206000 (97 MB) 2022-06-13 23:34:39 source > 2022-06-13 23:34:39 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 300000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:20.401 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 207000 (97 MB) 2022-06-13 23:34:39 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 208000 (98 MB) 2022-06-13 23:34:39 source > 2022-06-13 23:34:39 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 310000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:20.603 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 209000 (98 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 210000 (99 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 211000 (99 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 212000 (99 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 213000 (100 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 214000 (100 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 215000 (101 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 216000 (101 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 217000 (102 MB) 2022-06-13 23:34:40 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 218000 (102 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 219000 (103 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 220000 (103 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 221000 (104 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 222000 (104 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 223000 (105 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 224000 (105 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 225000 (106 MB) 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 226000 (106 MB) 2022-06-13 23:34:41 source > 2022-06-13 23:34:41 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 320000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:22.431 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 227000 (107 MB) 2022-06-13 23:34:41 source > 2022-06-13 23:34:41 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 330000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:22.583 2022-06-13 23:34:41 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 228000 (107 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 229000 (108 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 230000 (108 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 231000 (108 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 232000 (109 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 233000 (109 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 234000 (110 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 235000 (110 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 236000 (111 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 237000 (111 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 238000 (112 MB) 2022-06-13 23:34:42 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 239000 (112 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 240000 (113 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 241000 (113 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 242000 (114 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 243000 (114 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 244000 (115 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 245000 (115 MB) 2022-06-13 23:34:43 source > 2022-06-13 23:34:43 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 340000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:24.191 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 246000 (116 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 247000 (116 MB) 2022-06-13 23:34:43 source > 2022-06-13 23:34:43 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 350000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:24.38 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 248000 (116 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 249000 (117 MB) 2022-06-13 23:34:43 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 250000 (117 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 251000 (118 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 252000 (118 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 253000 (119 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 254000 (119 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 255000 (120 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 256000 (120 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 257000 (121 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 258000 (121 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 259000 (122 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 260000 (122 MB) 2022-06-13 23:34:44 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 261000 (123 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 262000 (123 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 263000 (124 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 264000 (124 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 265000 (125 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 266000 (125 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 267000 (125 MB) 2022-06-13 23:34:45 source > 2022-06-13 23:34:45 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 360000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:26.144 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 268000 (126 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 269000 (126 MB) 2022-06-13 23:34:45 source > 2022-06-13 23:34:45 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 370000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:26.365 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 270000 (127 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 271000 (127 MB) 2022-06-13 23:34:45 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 272000 (128 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 273000 (128 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 274000 (129 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 275000 (129 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 276000 (130 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 277000 (130 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 278000 (131 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 279000 (131 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 280000 (132 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 281000 (132 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 282000 (133 MB) 2022-06-13 23:34:46 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 283000 (133 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 284000 (133 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 285000 (134 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 286000 (134 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 287000 (135 MB) 2022-06-13 23:34:47 source > 2022-06-13 23:34:47 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 380000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:27.947 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 288000 (135 MB) 2022-06-13 23:34:47 source > 2022-06-13 23:34:47 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 390000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:28.163 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 289000 (136 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 290000 (136 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 291000 (137 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 292000 (137 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 293000 (138 MB) 2022-06-13 23:34:47 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 294000 (138 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 295000 (139 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 296000 (139 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 297000 (140 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 298000 (140 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 299000 (141 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 300000 (141 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 301000 (142 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 302000 (142 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 303000 (142 MB) 2022-06-13 23:34:48 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 304000 (143 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 305000 (143 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 306000 (144 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 307000 (144 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 308000 (145 MB) 2022-06-13 23:34:49 source > 2022-06-13 23:34:49 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 400000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:29.898 2022-06-13 23:34:49 source > 2022-06-13 23:34:49 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 410000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:29.996 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 309000 (145 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 310000 (146 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 311000 (146 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 312000 (147 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 313000 (147 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 314000 (148 MB) 2022-06-13 23:34:49 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 315000 (148 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 316000 (149 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 317000 (149 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 318000 (150 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 319000 (150 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 320000 (150 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 321000 (151 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 322000 (151 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 323000 (152 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 324000 (152 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 325000 (153 MB) 2022-06-13 23:34:50 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 326000 (153 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 327000 (154 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 328000 (154 MB) 2022-06-13 23:34:51 source > 2022-06-13 23:34:50 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 420000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:31.721 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 329000 (155 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 330000 (155 MB) 2022-06-13 23:34:51 source > 2022-06-13 23:34:51 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 430000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:31.967 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 331000 (156 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 332000 (156 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 333000 (157 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 334000 (157 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 335000 (158 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 336000 (158 MB) 2022-06-13 23:34:51 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 337000 (159 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 338000 (159 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 339000 (159 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 340000 (160 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 341000 (160 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 342000 (161 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 343000 (161 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 344000 (162 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 345000 (162 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 346000 (163 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 347000 (163 MB) 2022-06-13 23:34:52 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 348000 (164 MB) 2022-06-13 23:34:53 source > 2022-06-13 23:34:52 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 440000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:33.602 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 349000 (164 MB) 2022-06-13 23:34:53 source > 2022-06-13 23:34:52 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 450000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:33.795 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 350000 (165 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 351000 (165 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 352000 (166 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 353000 (166 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 354000 (167 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 355000 (167 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 356000 (167 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 357000 (168 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 358000 (168 MB) 2022-06-13 23:34:53 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 359000 (169 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 360000 (169 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 361000 (170 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 362000 (170 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 363000 (171 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 364000 (171 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 365000 (172 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 366000 (172 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 367000 (173 MB) 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 368000 (173 MB) 2022-06-13 23:34:54 source > 2022-06-13 23:34:54 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 460000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:35.501 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 369000 (174 MB) 2022-06-13 23:34:54 source > 2022-06-13 23:34:54 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 470000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:35.617 2022-06-13 23:34:54 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 370000 (174 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 371000 (175 MB) 2022-06-13 23:34:55 source > 2022-06-13 23:34:54 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 480000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:35.727 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 372000 (175 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 373000 (176 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 374000 (176 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 375000 (176 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 376000 (177 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 377000 (177 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 378000 (178 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 379000 (178 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 380000 (179 MB) 2022-06-13 23:34:55 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 381000 (179 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 382000 (180 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 383000 (180 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 384000 (181 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 385000 (181 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 386000 (182 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 387000 (182 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 388000 (183 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 389000 (183 MB) 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 390000 (184 MB) 2022-06-13 23:34:56 source > 2022-06-13 23:34:56 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 490000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:37.49 2022-06-13 23:34:56 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 391000 (184 MB) 2022-06-13 23:34:56 source > 2022-06-13 23:34:56 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 500000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:37.611 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 392000 (184 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 393000 (185 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 394000 (185 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 395000 (186 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 396000 (186 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 397000 (187 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 398000 (187 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 399000 (188 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 400000 (188 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 401000 (189 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 402000 (189 MB) 2022-06-13 23:34:57 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 403000 (190 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 404000 (190 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 405000 (191 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 406000 (191 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 407000 (192 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 408000 (192 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 409000 (193 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 410000 (193 MB) 2022-06-13 23:34:58 source > 2022-06-13 23:34:58 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 510000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:39.354 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 411000 (194 MB) 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 412000 (194 MB) 2022-06-13 23:34:58 source > 2022-06-13 23:34:58 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 520000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:39.501 2022-06-13 23:34:58 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 413000 (194 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 414000 (195 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 415000 (195 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 416000 (196 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 417000 (196 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 418000 (197 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 419000 (197 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 420000 (198 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 421000 (198 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 422000 (199 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 423000 (199 MB) 2022-06-13 23:34:59 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 424000 (200 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 425000 (200 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 426000 (201 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 427000 (201 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 428000 (202 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 429000 (202 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 430000 (203 MB) 2022-06-13 23:35:00 source > 2022-06-13 23:35:00 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 530000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:41.155 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 431000 (203 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 432000 (204 MB) 2022-06-13 23:35:00 source > 2022-06-13 23:35:00 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 540000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:41.287 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 433000 (204 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 434000 (204 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 435000 (205 MB) 2022-06-13 23:35:00 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 436000 (205 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 437000 (206 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 438000 (206 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 439000 (207 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 440000 (207 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 441000 (208 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 442000 (208 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 443000 (209 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 444000 (209 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 445000 (210 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 446000 (210 MB) 2022-06-13 23:35:01 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 447000 (211 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 448000 (211 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 449000 (212 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 450000 (212 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 451000 (213 MB) 2022-06-13 23:35:02 source > 2022-06-13 23:35:02 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 550000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:43.048 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 452000 (213 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 453000 (214 MB) 2022-06-13 23:35:02 source > 2022-06-13 23:35:02 INFO i.d.c.m.SnapshotReader(lambda$execute$16):677 - Step 7: - 560000 of 117801494 rows scanned from table 'mydb.mytable' after 00:00:43.205 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 454000 (214 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 455000 (214 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 456000 (215 MB) 2022-06-13 23:35:02 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 457000 (215 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 458000 (216 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 459000 (216 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 460000 (217 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 461000 (217 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 462000 (218 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 463000 (218 MB) 2022-06-13 23:35:03 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 464000 (219 MB) ... ... 2022-06-14 02:57:08 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127553000 (58 GB) 2022-06-14 02:57:08 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127554000 (58 GB) 2022-06-14 02:57:08 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127555000 (58 GB) 2022-06-14 02:57:08 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127556000 (58 GB) 2022-06-14 02:57:08 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127557000 (58 GB) 2022-06-14 02:57:08 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127558000 (58 GB) 2022-06-14 02:57:09 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127559000 (58 GB) 2022-06-14 02:57:09 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127560000 (58 GB) 2022-06-14 02:57:09 source > Jun 14, 2022 2:57:09 AM com.github.shyiko.mysql.binlog.BinaryLogClient connect 2022-06-14 02:57:09 source > INFO: Connected to my-hose:3306 at mysql-bin-changelog.225196/3722699 (sid:5961, cid:1773887) 2022-06-14 02:57:09 source > 2022-06-14 02:57:08 INFO i.d.c.m.ChainedReader(startNextReader):201 - Transitioning from the snapshot reader to the binlog reader 2022-06-14 02:57:09 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127561000 (58 GB) 2022-06-14 02:57:09 source > 2022-06-14 02:57:08 INFO i.d.c.m.BinlogReader(doStart):367 - GTID set purged on server: 2022-06-14 02:57:09 source > 2022-06-14 02:57:09 INFO i.d.u.Threads$3(newThread):287 - Creating thread debezium-mysqlconnector-mydb-binlog-client 2022-06-14 02:57:09 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127562000 (58 GB) 2022-06-14 02:57:09 source > 2022-06-14 02:57:09 INFO i.d.u.Threads$3(newThread):287 - Creating thread debezium-mysqlconnector-mydb-binlog-client 2022-06-14 02:57:09 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127563000 (58 GB) 2022-06-14 02:57:09 source > 2022-06-14 02:57:09 INFO i.d.c.m.BinlogReader$ReaderThreadLifecycleListener(onConnect):1128 - Connected to MySQL binlog at my-hose:3306, starting at binlog file 'mysql-bin-changelog.225196', pos=3722699, skipping 0 events plus 0 rows 2022-06-14 02:57:09 source > 2022-06-14 02:57:09 INFO i.d.c.m.BinlogReader(doStart):415 - Waiting for keepalive thread to start 2022-06-14 02:57:09 source > 2022-06-14 02:57:09 INFO i.d.u.Threads$3(newThread):287 - Creating thread debezium-mysqlconnector-mydb-binlog-client 2022-06-14 02:57:09 source > 2022-06-14 02:57:09 INFO i.d.c.m.BinlogReader(doStart):422 - Keepalive thread is running 2022-06-14 02:57:09 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127564000 (58 GB) 2022-06-14 02:57:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127565000 (58 GB) 2022-06-14 02:57:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127566000 (58 GB) 2022-06-14 02:57:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127567000 (58 GB) 2022-06-14 02:57:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127568000 (58 GB) 2022-06-14 02:57:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127569000 (58 GB) 2022-06-14 02:57:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127570000 (58 GB) 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.a.i.s.m.MySqlCdcTargetPosition(reachedTargetPosition):81 - Signalling close because record's binlog file : mysql-bin-changelog.225196 , position : 3722699 is after target file : mysql-bin-changelog.225196 , target position : 3713075 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.d.e.EmbeddedEngine(stop):996 - Stopping the embedded engine 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.d.e.EmbeddedEngine(stop):1004 - Waiting for PT5M for connector to stop 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.d.c.c.BaseSourceTask(stop):192 - Stopping down connector 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.d.c.m.MySqlConnectorTask(doStop):453 - Stopping MySQL connector task 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.d.c.m.ChainedReader(stop):121 - ChainedReader: Stopping the binlog reader 2022-06-14 02:57:11 source > 2022-06-14 02:57:10 INFO i.d.c.m.AbstractReader(stop):140 - Discarding 196 unsent record(s) due to the connector shutting down 2022-06-14 03:12:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127571000 (58 GB) 2022-06-14 03:12:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127572000 (58 GB) 2022-06-14 03:12:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127573000 (58 GB) 2022-06-14 03:12:10 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):344 - Records read: 127574000 (58 GB) 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 WARN i.a.i.b.IntegrationRunner(watchForOrphanThreads):241 - The main thread is exiting while children non-daemon threads from a connector are still active. 2022-06-14 03:12:10 source > Ideally, this situation should not happen... 2022-06-14 03:12:10 source > Please check with maintainers if the connector or library code should safely clean up its threads before quitting instead. 2022-06-14 03:12:10 source > The main thread is: main (RUNNABLE) 2022-06-14 03:12:10 source > Thread stacktrace: java.base/java.lang.Thread.getStackTrace(Thread.java:1610) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.IntegrationRunner.dumpThread(IntegrationRunner.java:276) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.IntegrationRunner.watchForOrphanThreads(IntegrationRunner.java:245) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.IntegrationRunner.produceMessages(IntegrationRunner.java:175) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.IntegrationRunner.lambda$runInternal$0(IntegrationRunner.java:156) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.sentry.AirbyteSentry.executeWithTracing(AirbyteSentry.java:54) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.sentry.AirbyteSentry.executeWithTracing(AirbyteSentry.java:38) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.IntegrationRunner.runInternal(IntegrationRunner.java:156) 2022-06-14 03:12:10 source > at io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:107) 2022-06-14 03:12:10 source > at io.airbyte.integrations.source.mysql.MySqlSource.main(MySqlSource.java:212) 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 WARN i.a.i.b.IntegrationRunner(watchForOrphanThreads):255 - Active non-daemon thread: pool-2-thread-1 (TIMED_WAITING) 2022-06-14 03:12:10 source > Thread stacktrace: java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:252) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:717) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireNanos(AbstractQueuedSynchronizer.java:986) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.ReentrantLock$Sync.tryLockNanos(ReentrantLock.java:168) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.ReentrantLock.tryLock(ReentrantLock.java:479) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.BinaryLogClient.tryLockInterruptibly(BinaryLogClient.java:1190) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.BinaryLogClient.terminateConnect(BinaryLogClient.java:1184) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.BinaryLogClient.disconnect(BinaryLogClient.java:1153) 2022-06-14 03:12:10 source > at app//io.debezium.connector.mysql.BinlogReader.doStop(BinlogReader.java:480) 2022-06-14 03:12:10 source > at app//io.debezium.connector.mysql.AbstractReader.stop(AbstractReader.java:141) 2022-06-14 03:12:10 source > at app//io.debezium.connector.mysql.ChainedReader.stop(ChainedReader.java:122) 2022-06-14 03:12:10 source > at app//io.debezium.connector.mysql.MySqlConnectorTask.doStop(MySqlConnectorTask.java:456) 2022-06-14 03:12:10 source > at app//io.debezium.connector.common.BaseSourceTask.stop(BaseSourceTask.java:206) 2022-06-14 03:12:10 source > at app//io.debezium.connector.common.BaseSourceTask.stop(BaseSourceTask.java:176) 2022-06-14 03:12:10 source > at app//io.debezium.embedded.EmbeddedEngine.run(EmbeddedEngine.java:838) 2022-06-14 03:12:10 source > at app//io.debezium.embedded.ConvertingEngineBuilder$2.run(ConvertingEngineBuilder.java:171) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.lang.Thread.run(Thread.java:833) 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 WARN i.a.i.b.IntegrationRunner(watchForOrphanThreads):255 - Active non-daemon thread: FileOffsetBackingStore-1 (WAITING) 2022-06-14 03:12:10 source > Thread stacktrace: java.base@17.0.1/jdk.internal.misc.Unsafe.park(Native Method) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.LockSupport.park(LockSupport.java:341) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:506) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3463) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3434) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1623) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:435) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1062) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1122) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.lang.Thread.run(Thread.java:833) 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 WARN i.a.i.b.IntegrationRunner(watchForOrphanThreads):255 - Active non-daemon thread: blc-my-hose:3306 (RUNNABLE) 2022-06-14 03:12:10 source > Thread stacktrace: java.base@17.0.1/java.io.InputStream.read(InputStream.java:293) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.io.InputStream.skip(InputStream.java:547) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.io.ByteArrayInputStream.skipToTheEndOfTheBlock(ByteArrayInputStream.java:219) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.deserializeEventData(EventDeserializer.java:300) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.event.deserialization.EventDeserializer.nextEvent(EventDeserializer.java:227) 2022-06-14 03:12:10 source > at app//io.debezium.connector.mysql.BinlogReader$1.nextEvent(BinlogReader.java:252) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.BinaryLogClient.listenForEventPackets(BinaryLogClient.java:934) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.BinaryLogClient.connect(BinaryLogClient.java:595) 2022-06-14 03:12:10 source > at app//com.github.shyiko.mysql.binlog.BinaryLogClient$7.run(BinaryLogClient.java:839) 2022-06-14 03:12:10 source > at java.base@17.0.1/java.lang.Thread.run(Thread.java:833) 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 INFO i.a.i.s.r.AbstractDbSource(lambda$read$2):130 - Closing database connection pool. 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 INFO c.z.h.HikariDataSource(close):350 - HikariPool-1 - Shutdown initiated... 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 INFO c.z.h.HikariDataSource(close):352 - HikariPool-1 - Shutdown completed. 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 INFO i.a.i.s.r.AbstractDbSource(lambda$read$2):132 - Closed database connection pool. 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 INFO i.a.i.b.IntegrationRunner(runInternal):171 - Completed integration: io.airbyte.integrations.base.ssh.SshWrappedSource 2022-06-14 03:12:10 source > 2022-06-14 03:12:10 INFO i.a.i.s.m.MySqlSource(main):213 - completed source: class io.airbyte.integrations.source.mysql.MySqlSource 2022-06-14 04:22:10 source > 2022-06-14 04:22:10 ERROR i.a.i.b.IntegrationRunner(lambda$watchForOrphanThreads$8):266 - Failed to interrupt children non-daemon threads, forcefully exiting NOW... 2022-06-14 04:22:10 INFO i.a.v.j.JsonSchemaValidator(test):71 - JSON schema validation failed. errors: $: unknown found, object expected 2022-06-14 04:22:10 ERROR i.a.w.i.DefaultAirbyteStreamFactory(lambda$create$1):70 - Validation failed: null 2022-06-14 04:22:12 INFO i.a.w.g.DefaultReplicationWorker(lambda$getReplicationRunnable$6):347 - Source has no more messages, closing connection. 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):65 - Airbyte message consumer: succeeded. 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.d.b.BufferedStreamConsumer(close):170 - executing on success close procedure. 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.d.r.SerializedBufferingStrategy(flushAll):92 - Flushing all 1 current buffers (129 MB in total) 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.d.r.SerializedBufferingStrategy(lambda$flushAll$2):95 - Flushing buffer of stream mytable (129 MB) 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.d.s.StagingConsumerFactory(lambda$flushBufferFunction$3):158 - Flushing buffer for stream mytable (129 MB) to staging 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.d.r.BaseSerializedBuffer(flush):131 - Wrapping up compression and write GZIP trailer data. 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO i.a.i.d.r.BaseSerializedBuffer(flush):138 - Finished writing data to 92f9d0b5-9943-47d0-b663-9321d983d8304624231387292904506.csv.gz (129 MB) 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(getMultiPartOutputStreams):329 - Initiated multipart upload to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with full ID _WguNHvclmVSRpz5XmEXJHeBDAYEk6eorXNpoVXZgGLivutFV3LVhxjBctd0jikqcmtwgNuW7GuESvMOzBsLIcRv358vmto6sjzMuO8JpN0qXlCGHTlY2xM8eqPJEDDn 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.MultiPartOutputStream(close):158 - Called close() on [MultipartOutputStream for parts 1 - 10000] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 1 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 2 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 6 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 3 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 5 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 8 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 7 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 4 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 10 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 11 containing 10.01 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 13 containing 9.03 MB] 2022-06-14 04:22:12 destination > 2022-06-14 04:22:12 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 12 containing 10.01 MB] 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO a.m.s.StreamTransferManager(uploadStreamPart):558 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Finished uploading [Part number 9 containing 10.01 MB] 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO a.m.s.StreamTransferManager(complete):395 - [Manager uploading to my-bucket/MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz with id _WguNHvcl...8eqPJEDDn]: Completed 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO i.a.i.d.s.S3StorageOperations(loadDataIntoBucket):178 - Uploaded buffer file to storage: 92f9d0b5-9943-47d0-b663-9321d983d8304624231387292904506.csv.gz -> MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/32.csv.gz (filename: 32.csv.gz) 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO i.a.i.d.r.FileBuffer(deleteFile):81 - Deleting tempFile data 92f9d0b5-9943-47d0-b663-9321d983d8304624231387292904506.csv.gz 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO i.a.i.d.r.SerializedBufferingStrategy(close):119 - Closing buffer for stream mytable 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO i.a.i.d.s.StagingConsumerFactory(lambda$onCloseFunction$4):186 - Copying into tables in destination started for 1 streams 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO i.a.i.d.s.StagingConsumerFactory(lambda$onCloseFunction$4):195 - Copying stream mytable of schema MY_SCHEMA into tmp table _airbyte_tmp_mbc_mytable to final table _AIRBYTE_RAW_MY_TABLE from stage path MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/ with 33 file(s) [0.csv.gz,1.csv.gz,2.csv.gz,3.csv.gz,4.csv.gz,5.csv.gz,6.csv.gz,7.csv.gz,8.csv.gz,9.csv.gz,10.csv.gz,11.csv.gz,12.csv.gz,13.csv.gz,14.csv.gz,15.csv.gz,16.csv.gz,17.csv.gz,18.csv.gz,19.csv.gz,20.csv.gz,21.csv.gz,22.csv.gz,23.csv.gz,24.csv.gz,25.csv.gz,26.csv.gz,27.csv.gz,28.csv.gz,29.csv.gz,30.csv.gz,31.csv.gz,32.csv.gz] 2022-06-14 04:22:14 destination > 2022-06-14 04:22:14 INFO i.a.i.d.s.SnowflakeS3StagingSqlOperations(copyIntoTmpTableFromStage):101 - Starting copy to tmp table from stage: _airbyte_tmp_mbc_mytable in destination from stage: MY_SCHEMA_MYTABLE/2022/06/13/23/CBA85027-0B1A-4DCC-BDB4-052BA187146B/, schema: MY_SCHEMA, . 2022-06-14 04:23:14 ERROR i.a.w.g.DefaultReplicationWorker(run):180 - Sync worker failed. java.util.concurrent.ExecutionException: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped! at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?] at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?] at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:173) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:65) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.lang.Thread.run(Thread.java:833) [?:?] Suppressed: io.airbyte.workers.exception.WorkerException: Source process exit with code 2. This warning is normal if the job was cancelled. at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:137) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:65) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.lang.Thread.run(Thread.java:833) [?:?] Suppressed: io.airbyte.workers.exception.WorkerException: Destination process exit with code 143. This warning is normal if the job was cancelled. at io.airbyte.workers.internal.DefaultAirbyteDestination.close(DefaultAirbyteDestination.java:119) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:137) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultReplicationWorker.run(DefaultReplicationWorker.java:65) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.lang.Thread.run(Thread.java:833) [?:?] Caused by: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped! at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:351) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?] ... 1 more Caused by: io.airbyte.workers.exception.WorkerException: Source process exit with code 2. This warning is normal if the job was cancelled. at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:349) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?] ... 1 more 2022-06-14 04:23:14 INFO i.a.w.g.DefaultReplicationWorker(run):239 - sync summary: io.airbyte.config.ReplicationAttemptSummary@7593c512[status=failed,recordsSynced=127574094,bytesSynced=62486605543,startTime=1655163251413,endTime=1655180594022,totalStats=io.airbyte.config.SyncStats@787b7435[recordsEmitted=127574094,bytesEmitted=62486605543,stateMessagesEmitted=1,recordsCommitted=0],streamStats=[io.airbyte.config.StreamSyncStats@7663a3af[streamName=mytable,stats=io.airbyte.config.SyncStats@5f0ef309[recordsEmitted=127574094,bytesEmitted=62486605543,stateMessagesEmitted=,recordsCommitted=]]]] 2022-06-14 04:23:14 INFO i.a.w.g.DefaultReplicationWorker(run):266 - Source output at least one state message 2022-06-14 04:23:14 WARN i.a.w.g.DefaultReplicationWorker(run):279 - State capture: No state retained. 2022-06-14 04:23:14 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling... at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315) at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320) at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) Caused by: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped! at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:351) at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ... 3 more Caused by: io.airbyte.workers.exception.WorkerException: Source process exit with code 2. This warning is normal if the job was cancelled. at io.airbyte.workers.internal.DefaultAirbyteSource.close(DefaultAirbyteSource.java:136) at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:349) ... 4 more ,retryable=,timestamp=1655180532332], io.airbyte.config.FailureReason@7f1f45d6[failureOrigin=replication,failureType=,internalMessage=java.lang.RuntimeException: java.io.UncheckedIOException: java.io.IOException: Stream closed,externalMessage=Something went wrong during replication,metadata=io.airbyte.config.Metadata@40085e0c[additionalProperties={attemptNumber=0, jobId=26613}],stacktrace=java.util.concurrent.CompletionException: java.lang.RuntimeException: java.io.UncheckedIOException: java.io.IOException: Stream closed at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:315) at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:320) at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1807) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) Caused by: java.lang.RuntimeException: java.io.UncheckedIOException: java.io.IOException: Stream closed at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getDestinationOutputRunnable$7(DefaultReplicationWorker.java:423) at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ... 3 more Caused by: java.io.UncheckedIOException: java.io.IOException: Stream closed at java.base/java.io.BufferedReader$1.hasNext(BufferedReader.java:574) at java.base/java.util.Spliterators$IteratorSpliterator.tryAdvance(Spliterators.java:1855) at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(StreamSpliterators.java:292) at java.base/java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(StreamSpliterators.java:206) at java.base/java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(StreamSpliterators.java:161) at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(StreamSpliterators.java:298) at java.base/java.util.Spliterators$1Adapter.hasNext(Spliterators.java:681) at io.airbyte.workers.internal.DefaultAirbyteDestination.isFinished(DefaultAirbyteDestination.java:141) at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getDestinationOutputRunnable$7(DefaultReplicationWorker.java:397) ... 4 more Caused by: java.io.IOException: Stream closed at java.base/java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:168) at java.base/java.io.BufferedInputStream.read(BufferedInputStream.java:334) at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:270) at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:313) at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:188) at java.base/java.io.InputStreamReader.read(InputStreamReader.java:177) at java.base/java.io.BufferedReader.fill(BufferedReader.java:162) at java.base/java.io.BufferedReader.readLine(BufferedReader.java:329) at java.base/java.io.BufferedReader.readLine(BufferedReader.java:396) at java.base/java.io.BufferedReader$1.hasNext(BufferedReader.java:571) ... 12 more ,retryable=,timestamp=1655180594018]]] 2022-06-14 04:23:14 INFO i.a.w.t.TemporalUtils(withBackgroundHeartbeat):236 - Stopping temporal heartbeating... 2022-06-14 04:23:14 INFO i.a.w.t.TemporalAttemptExecution(get):108 - Docker volume job log path: /tmp/workspace/26613/0/logs.log 2022-06-14 04:23:14 INFO i.a.w.t.TemporalAttemptExecution(get):113 - Executing worker wrapper. Airbyte version: 0.39.13-alpha 2022-06-14 04:23:14 INFO i.a.w.g.DefaultNormalizationWorker(run):49 - Running normalization. 2022-06-14 04:23:14 INFO i.a.w.n.DefaultNormalizationRunner(runProcess):122 - Running with normalization version: airbyte/normalization-snowflake:0.2.1 2022-06-14 04:23:14 INFO i.a.c.i.LineGobbler(voidCall):82 - Checking if airbyte/normalization-snowflake:0.2.1 exists... 2022-06-14 04:23:14 INFO i.a.c.i.LineGobbler(voidCall):82 - airbyte/normalization-snowflake:0.2.1 was found locally. 2022-06-14 04:23:14 INFO i.a.w.p.DockerProcessFactory(create):108 - Creating docker job ID: 26613 2022-06-14 04:23:14 INFO i.a.w.p.DockerProcessFactory(create):163 - Preparing command: docker run --rm --init -i -w /data/26613/0/normalize --log-driver none --name normalization-snowflake-normalize-26613-0-hxviw --network host -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -e WORKER_ENVIRONMENT=DOCKER -e AIRBYTE_ROLE= -e AIRBYTE_VERSION=0.39.13-alpha airbyte/normalization-snowflake:0.2.1 run --integration-type snowflake --config destination_config.json --catalog destination_catalog.json 2022-06-14 04:23:17 normalization > Running: transform-config --config destination_config.json --integration-type snowflake --out /data/26613/0/normalize 2022-06-14 04:23:18 normalization > Namespace(config='destination_config.json', integration_type=, out='/data/26613/0/normalize') 2022-06-14 04:23:18 normalization > transform_snowflake 2022-06-14 04:23:18 normalization > Running: transform-catalog --integration-type snowflake --profile-config-dir /data/26613/0/normalize --catalog destination_catalog.json --out /data/26613/0/normalize/models/generated/ --json-column _airbyte_data 2022-06-14 04:23:18 normalization > Processing destination_catalog.json... 2022-06-14 04:23:18 normalization > Generating airbyte_ctes/MY_SCHEMA/MYTABLE_AB1.sql from mytable 2022-06-14 04:23:18 normalization > Generating airbyte_ctes/MY_SCHEMA/MYTABLE_AB2.sql from mytable 2022-06-14 04:23:18 normalization > Generating airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql from mytable 2022-06-14 04:23:18 normalization > Generating airbyte_incremental/scd/MY_SCHEMA/MY_TABLE_SCD.sql from mytable 2022-06-14 04:23:18 normalization > Generating airbyte_incremental/MY_SCHEMA/MYTABLE.sql from mytable 2022-06-14 04:23:18 normalization > detected no config file for ssh, assuming ssh is off. 2022-06-14 04:23:21 normalization > [--event-buffer-size EVENT_BUFFER_SIZE] 2022-06-14 04:23:21 normalization > --event-buffer-size EVENT_BUFFER_SIZE 2022-06-14 04:23:21 normalization > 2022-06-14 04:23:21 normalization > DBT >=1.0.0 detected; using 10K event buffer size 2022-06-14 04:23:21 normalization > 2022-06-14 04:23:23 normalization > 04:23:23 Running with dbt=1.0.0 2022-06-14 04:23:23 normalization > 04:23:23 Partial parse save file not found. Starting full parse. 2022-06-14 04:23:25 normalization > 04:23:25 [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources. 2022-06-14 04:23:25 normalization > There are 1 unused configuration paths: 2022-06-14 04:23:25 normalization > - models.airbyte_utils.generated.airbyte_tables 2022-06-14 04:23:25 normalization > 2022-06-14 04:23:26 normalization > 04:23:26 Found 5 models, 0 tests, 0 snapshots, 0 analyses, 535 macros, 0 operations, 0 seed files, 1 source, 0 exposures, 0 metrics 2022-06-14 04:23:26 normalization > 04:23:26 2022-06-14 04:23:29 normalization > 04:23:29 Concurrency: 5 threads (target='prod') 2022-06-14 04:23:29 normalization > 04:23:29 2022-06-14 04:23:30 normalization > 04:23:30 1 of 3 START view model _AIRBYTE_MY_SCHEMA.MY_TABLE_STG.......................................................... [RUN] 2022-06-14 04:23:31 normalization > 04:23:31 1 of 3 ERROR creating view model _AIRBYTE_MY_SCHEMA.MY_TABLE_STG................................................. [ERROR in 1.26s] 2022-06-14 04:23:31 normalization > 04:23:31 2 of 3 SKIP relation MY_SCHEMA.MY_TABLE_SCD...................................................................... [SKIP] 2022-06-14 04:23:31 normalization > 04:23:31 3 of 3 SKIP relation MY_SCHEMA.MY_TABLE.......................................................................... [SKIP] 2022-06-14 04:23:31 normalization > 04:23:31 2022-06-14 04:23:31 normalization > 04:23:31 Finished running 1 view model, 2 incremental models in 5.50s. 2022-06-14 04:23:31 normalization > 04:23:31 2022-06-14 04:23:31 normalization > 04:23:31 Completed with 1 error and 0 warnings: 2022-06-14 04:23:31 normalization > 04:23:31 2022-06-14 04:23:31 normalization > 04:23:31 Database Error in model MY_TABLE_STG (models/generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql) 2022-06-14 04:23:31 normalization > 04:23:31 002003 (42S02): SQL compilation error: 2022-06-14 04:23:31 normalization > 04:23:31 Object 'MY_DB.MY_SCHEMA._AIRBYTE_RAW_MY_TABLE' does not exist or not authorized. 2022-06-14 04:23:31 normalization > 04:23:31 compiled SQL at ../build/run/airbyte_utils/models/generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql 2022-06-14 04:23:31 normalization > 04:23:31 2022-06-14 04:23:31 normalization > 04:23:31 Done. PASS=0 WARN=0 ERROR=1 SKIP=2 TOTAL=3 2022-06-14 04:23:31 normalization > 2022-06-14 04:23:31 normalization > Diagnosing dbt debug to check if destination is available for dbt and well configured (1): 2022-06-14 04:23:31 normalization > 2022-06-14 04:23:34 normalization > 04:23:34 Running with dbt=1.0.0 2022-06-14 04:23:34 normalization > dbt version: 1.0.0 2022-06-14 04:23:34 normalization > python version: 3.9.9 2022-06-14 04:23:34 normalization > python path: /usr/local/bin/python 2022-06-14 04:23:34 normalization > os info: Linux-4.14.275-142.503.amzn1.x86_64-x86_64-with-glibc2.31 2022-06-14 04:23:34 normalization > Using profiles.yml file at /data/26613/0/normalize/profiles.yml 2022-06-14 04:23:34 normalization > Using dbt_project.yml file at /data/26613/0/normalize/dbt_project.yml 2022-06-14 04:23:34 normalization > 2022-06-14 04:23:34 normalization > Configuration: 2022-06-14 04:23:34 normalization > profiles.yml file [OK found and valid] 2022-06-14 04:23:34 normalization > dbt_project.yml file [OK found and valid] 2022-06-14 04:23:34 normalization > 2022-06-14 04:23:34 normalization > Required dependencies: 2022-06-14 04:23:34 normalization > - git [OK found] 2022-06-14 04:23:34 normalization > 2022-06-14 04:23:34 normalization > Connection: 2022-06-14 04:23:34 normalization > account: vistaprint.eu-west-1 2022-06-14 04:23:34 normalization > user: SVC_JZF8SMUAIJJAQJGYKCNOC41XIIGPYYCR_347073262504660 2022-06-14 04:23:34 normalization > database: MY_DB 2022-06-14 04:23:34 normalization > schema: _ANALYTICS 2022-06-14 04:23:34 normalization > warehouse: PUBLIC 2022-06-14 04:23:34 normalization > role: MY_DB_CURATOR_V2 2022-06-14 04:23:34 normalization > client_session_keep_alive: False 2022-06-14 04:23:35 normalization > Connection test: [OK connection ok] 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > All checks passed! 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > Forward dbt output logs to diagnose/debug errors (0): 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > ============================== 2022-06-14 04:23:23.562418 | 28352a32-9071-4499-a2d4-d558b30e1750 ============================== 2022-06-14 04:23:35 normalization > 04:23:23.562418 [info ] [MainThread]: Running with dbt=1.0.0 2022-06-14 04:23:35 normalization > 04:23:23.562950 [debug] [MainThread]: running dbt with arguments Namespace(record_timing_info=None, debug=None, log_format=None, write_json=None, use_colors=None, printer_width=None, warn_error=None, version_check=None, partial_parse=None, single_threaded=False, use_experimental_parser=None, static_parser=None, profiles_dir='/data/26613/0/normalize', send_anonymous_usage_stats=None, fail_fast=None, event_buffer_size='10000', project_dir='/data/26613/0/normalize', profile=None, target=None, vars='{}', log_cache_events=False, threads=None, select=None, exclude=None, selector_name=None, state=None, defer=None, full_refresh=False, cls=, which='run', rpc_method='run') 2022-06-14 04:23:35 normalization > 04:23:23.568222 [debug] [MainThread]: Tracking: do not track 2022-06-14 04:23:35 normalization > 04:23:23.597377 [info ] [MainThread]: Partial parse save file not found. Starting full parse. 2022-06-14 04:23:35 normalization > 04:23:23.763903 [debug] [MainThread]: Parsing macros/incremental.sql 2022-06-14 04:23:35 normalization > 04:23:23.776778 [debug] [MainThread]: Parsing macros/star_intersect.sql 2022-06-14 04:23:35 normalization > 04:23:23.788226 [debug] [MainThread]: Parsing macros/get_custom_schema.sql 2022-06-14 04:23:35 normalization > 04:23:23.800638 [debug] [MainThread]: Parsing macros/configuration.sql 2022-06-14 04:23:35 normalization > 04:23:23.809012 [debug] [MainThread]: Parsing macros/should_full_refresh.sql 2022-06-14 04:23:35 normalization > 04:23:23.819255 [debug] [MainThread]: Parsing macros/schema_tests/equality.sql 2022-06-14 04:23:35 normalization > 04:23:23.830965 [debug] [MainThread]: Parsing macros/schema_tests/equal_rowcount.sql 2022-06-14 04:23:35 normalization > 04:23:23.838173 [debug] [MainThread]: Parsing macros/cross_db_utils/type_conversions.sql 2022-06-14 04:23:35 normalization > 04:23:23.851768 [debug] [MainThread]: Parsing macros/cross_db_utils/current_timestamp.sql 2022-06-14 04:23:35 normalization > 04:23:23.857851 [debug] [MainThread]: Parsing macros/cross_db_utils/quote.sql 2022-06-14 04:23:35 normalization > 04:23:23.864337 [debug] [MainThread]: Parsing macros/cross_db_utils/hash.sql 2022-06-14 04:23:35 normalization > 04:23:23.869749 [debug] [MainThread]: Parsing macros/cross_db_utils/surrogate_key.sql 2022-06-14 04:23:35 normalization > 04:23:23.877191 [debug] [MainThread]: Parsing macros/cross_db_utils/concat.sql 2022-06-14 04:23:35 normalization > 04:23:23.884597 [debug] [MainThread]: Parsing macros/cross_db_utils/array.sql 2022-06-14 04:23:35 normalization > 04:23:23.904167 [debug] [MainThread]: Parsing macros/cross_db_utils/datatypes.sql 2022-06-14 04:23:35 normalization > 04:23:23.920088 [debug] [MainThread]: Parsing macros/cross_db_utils/json_operations.sql 2022-06-14 04:23:35 normalization > 04:23:23.962337 [debug] [MainThread]: Parsing macros/cross_db_utils/except.sql 2022-06-14 04:23:35 normalization > 04:23:23.969621 [debug] [MainThread]: Parsing macros/cross_db_utils/columns.sql 2022-06-14 04:23:35 normalization > 04:23:23.977240 [debug] [MainThread]: Parsing macros/adapters.sql 2022-06-14 04:23:35 normalization > 04:23:24.023375 [debug] [MainThread]: Parsing macros/catalog.sql 2022-06-14 04:23:35 normalization > 04:23:24.031231 [debug] [MainThread]: Parsing macros/materializations/incremental.sql 2022-06-14 04:23:35 normalization > 04:23:24.045935 [debug] [MainThread]: Parsing macros/materializations/merge.sql 2022-06-14 04:23:35 normalization > 04:23:24.055441 [debug] [MainThread]: Parsing macros/materializations/seed.sql 2022-06-14 04:23:35 normalization > 04:23:24.067005 [debug] [MainThread]: Parsing macros/materializations/snapshot.sql 2022-06-14 04:23:35 normalization > 04:23:24.073605 [debug] [MainThread]: Parsing macros/materializations/table.sql 2022-06-14 04:23:35 normalization > 04:23:24.082934 [debug] [MainThread]: Parsing macros/materializations/view.sql 2022-06-14 04:23:35 normalization > 04:23:24.090802 [debug] [MainThread]: Parsing macros/adapters/columns.sql 2022-06-14 04:23:35 normalization > 04:23:24.106957 [debug] [MainThread]: Parsing macros/adapters/freshness.sql 2022-06-14 04:23:35 normalization > 04:23:24.115371 [debug] [MainThread]: Parsing macros/adapters/indexes.sql 2022-06-14 04:23:35 normalization > 04:23:24.123686 [debug] [MainThread]: Parsing macros/adapters/metadata.sql 2022-06-14 04:23:35 normalization > 04:23:24.136951 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql 2022-06-14 04:23:35 normalization > 04:23:24.147044 [debug] [MainThread]: Parsing macros/adapters/relation.sql 2022-06-14 04:23:35 normalization > 04:23:24.162037 [debug] [MainThread]: Parsing macros/adapters/schema.sql 2022-06-14 04:23:35 normalization > 04:23:24.170091 [debug] [MainThread]: Parsing macros/etc/datetime.sql 2022-06-14 04:23:35 normalization > 04:23:24.183840 [debug] [MainThread]: Parsing macros/etc/statement.sql 2022-06-14 04:23:35 normalization > 04:23:24.193492 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql 2022-06-14 04:23:35 normalization > 04:23:24.200398 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql 2022-06-14 04:23:35 normalization > 04:23:24.205946 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql 2022-06-14 04:23:35 normalization > 04:23:24.212199 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql 2022-06-14 04:23:35 normalization > 04:23:24.218397 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql 2022-06-14 04:23:35 normalization > 04:23:24.225459 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql 2022-06-14 04:23:35 normalization > 04:23:24.233345 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql 2022-06-14 04:23:35 normalization > 04:23:24.241121 [debug] [MainThread]: Parsing macros/materializations/configs.sql 2022-06-14 04:23:35 normalization > 04:23:24.248811 [debug] [MainThread]: Parsing macros/materializations/hooks.sql 2022-06-14 04:23:35 normalization > 04:23:24.257406 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql 2022-06-14 04:23:35 normalization > 04:23:24.267814 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql 2022-06-14 04:23:35 normalization > 04:23:24.284053 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql 2022-06-14 04:23:35 normalization > 04:23:24.291195 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql 2022-06-14 04:23:35 normalization > 04:23:24.308680 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql 2022-06-14 04:23:35 normalization > 04:23:24.330553 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql 2022-06-14 04:23:35 normalization > 04:23:24.339422 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql 2022-06-14 04:23:35 normalization > 04:23:24.352653 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql 2022-06-14 04:23:35 normalization > 04:23:24.360776 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql 2022-06-14 04:23:35 normalization > 04:23:24.368855 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql 2022-06-14 04:23:35 normalization > 04:23:24.375710 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql 2022-06-14 04:23:35 normalization > 04:23:24.388610 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql 2022-06-14 04:23:35 normalization > 04:23:24.414075 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql 2022-06-14 04:23:35 normalization > 04:23:24.425691 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql 2022-06-14 04:23:35 normalization > 04:23:24.442881 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql 2022-06-14 04:23:35 normalization > 04:23:24.460170 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql 2022-06-14 04:23:35 normalization > 04:23:24.467264 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql 2022-06-14 04:23:35 normalization > 04:23:24.490557 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql 2022-06-14 04:23:35 normalization > 04:23:24.497301 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql 2022-06-14 04:23:35 normalization > 04:23:24.507055 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql 2022-06-14 04:23:35 normalization > 04:23:24.514744 [debug] [MainThread]: Parsing tests/generic/builtin.sql 2022-06-14 04:23:35 normalization > 04:23:24.524090 [debug] [MainThread]: Parsing macros/cross_db_utils/_is_ephemeral.sql 2022-06-14 04:23:35 normalization > 04:23:24.531323 [debug] [MainThread]: Parsing macros/cross_db_utils/_is_relation.sql 2022-06-14 04:23:35 normalization > 04:23:24.537500 [debug] [MainThread]: Parsing macros/cross_db_utils/any_value.sql 2022-06-14 04:23:35 normalization > 04:23:24.547288 [debug] [MainThread]: Parsing macros/cross_db_utils/bool_or.sql 2022-06-14 04:23:35 normalization > 04:23:24.554299 [debug] [MainThread]: Parsing macros/cross_db_utils/cast_bool_to_text.sql 2022-06-14 04:23:35 normalization > 04:23:24.561022 [debug] [MainThread]: Parsing macros/cross_db_utils/concat.sql 2022-06-14 04:23:35 normalization > 04:23:24.566724 [debug] [MainThread]: Parsing macros/cross_db_utils/current_timestamp.sql 2022-06-14 04:23:35 normalization > 04:23:24.575988 [debug] [MainThread]: Parsing macros/cross_db_utils/datatypes.sql 2022-06-14 04:23:35 normalization > 04:23:24.588094 [debug] [MainThread]: Parsing macros/cross_db_utils/date_trunc.sql 2022-06-14 04:23:35 normalization > 04:23:24.595971 [debug] [MainThread]: Parsing macros/cross_db_utils/dateadd.sql 2022-06-14 04:23:35 normalization > 04:23:24.604613 [debug] [MainThread]: Parsing macros/cross_db_utils/datediff.sql 2022-06-14 04:23:35 normalization > 04:23:24.620949 [debug] [MainThread]: Parsing macros/cross_db_utils/escape_single_quotes.sql 2022-06-14 04:23:35 normalization > 04:23:24.627933 [debug] [MainThread]: Parsing macros/cross_db_utils/except.sql 2022-06-14 04:23:35 normalization > 04:23:24.634407 [debug] [MainThread]: Parsing macros/cross_db_utils/hash.sql 2022-06-14 04:23:35 normalization > 04:23:24.640856 [debug] [MainThread]: Parsing macros/cross_db_utils/identifier.sql 2022-06-14 04:23:35 normalization > 04:23:24.647771 [debug] [MainThread]: Parsing macros/cross_db_utils/intersect.sql 2022-06-14 04:23:35 normalization > 04:23:24.654332 [debug] [MainThread]: Parsing macros/cross_db_utils/last_day.sql 2022-06-14 04:23:35 normalization > 04:23:24.664070 [debug] [MainThread]: Parsing macros/cross_db_utils/length.sql 2022-06-14 04:23:35 normalization > 04:23:24.670819 [debug] [MainThread]: Parsing macros/cross_db_utils/literal.sql 2022-06-14 04:23:35 normalization > 04:23:24.677353 [debug] [MainThread]: Parsing macros/cross_db_utils/position.sql 2022-06-14 04:23:35 normalization > 04:23:24.683836 [debug] [MainThread]: Parsing macros/cross_db_utils/replace.sql 2022-06-14 04:23:35 normalization > 04:23:24.690928 [debug] [MainThread]: Parsing macros/cross_db_utils/right.sql 2022-06-14 04:23:35 normalization > 04:23:24.698180 [debug] [MainThread]: Parsing macros/cross_db_utils/safe_cast.sql 2022-06-14 04:23:35 normalization > 04:23:24.705050 [debug] [MainThread]: Parsing macros/cross_db_utils/split_part.sql 2022-06-14 04:23:35 normalization > 04:23:24.713030 [debug] [MainThread]: Parsing macros/cross_db_utils/width_bucket.sql 2022-06-14 04:23:35 normalization > 04:23:24.723490 [debug] [MainThread]: Parsing macros/jinja_helpers/log_info.sql 2022-06-14 04:23:35 normalization > 04:23:24.730037 [debug] [MainThread]: Parsing macros/jinja_helpers/pretty_log_format.sql 2022-06-14 04:23:35 normalization > 04:23:24.736678 [debug] [MainThread]: Parsing macros/jinja_helpers/pretty_time.sql 2022-06-14 04:23:35 normalization > 04:23:24.744157 [debug] [MainThread]: Parsing macros/jinja_helpers/slugify.sql 2022-06-14 04:23:35 normalization > 04:23:24.750119 [debug] [MainThread]: Parsing macros/materializations/insert_by_period_materialization.sql 2022-06-14 04:23:35 normalization > 04:23:24.781858 [debug] [MainThread]: Parsing macros/schema_tests/accepted_range.sql 2022-06-14 04:23:35 normalization > 04:23:24.790036 [debug] [MainThread]: Parsing macros/schema_tests/at_least_one.sql 2022-06-14 04:23:35 normalization > 04:23:24.796712 [debug] [MainThread]: Parsing macros/schema_tests/cardinality_equality.sql 2022-06-14 04:23:35 normalization > 04:23:24.804897 [debug] [MainThread]: Parsing macros/schema_tests/equal_rowcount.sql 2022-06-14 04:23:35 normalization > 04:23:24.811951 [debug] [MainThread]: Parsing macros/schema_tests/equality.sql 2022-06-14 04:23:35 normalization > 04:23:24.820974 [debug] [MainThread]: Parsing macros/schema_tests/expression_is_true.sql 2022-06-14 04:23:35 normalization > 04:23:24.828100 [debug] [MainThread]: Parsing macros/schema_tests/fewer_rows_than.sql 2022-06-14 04:23:35 normalization > 04:23:24.837458 [debug] [MainThread]: Parsing macros/schema_tests/mutually_exclusive_ranges.sql 2022-06-14 04:23:35 normalization > 04:23:24.852269 [debug] [MainThread]: Parsing macros/schema_tests/not_accepted_values.sql 2022-06-14 04:23:35 normalization > 04:23:24.860305 [debug] [MainThread]: Parsing macros/schema_tests/not_constant.sql 2022-06-14 04:23:35 normalization > 04:23:24.866640 [debug] [MainThread]: Parsing macros/schema_tests/not_null_proportion.sql 2022-06-14 04:23:35 normalization > 04:23:24.874460 [debug] [MainThread]: Parsing macros/schema_tests/recency.sql 2022-06-14 04:23:35 normalization > 04:23:24.881473 [debug] [MainThread]: Parsing macros/schema_tests/relationships_where.sql 2022-06-14 04:23:35 normalization > 04:23:24.889007 [debug] [MainThread]: Parsing macros/schema_tests/sequential_values.sql 2022-06-14 04:23:35 normalization > 04:23:24.897623 [debug] [MainThread]: Parsing macros/schema_tests/test_not_null_where.sql 2022-06-14 04:23:35 normalization > 04:23:24.903972 [debug] [MainThread]: Parsing macros/schema_tests/test_unique_where.sql 2022-06-14 04:23:35 normalization > 04:23:24.911392 [debug] [MainThread]: Parsing macros/schema_tests/unique_combination_of_columns.sql 2022-06-14 04:23:35 normalization > 04:23:24.919362 [debug] [MainThread]: Parsing macros/sql/date_spine.sql 2022-06-14 04:23:35 normalization > 04:23:24.928789 [debug] [MainThread]: Parsing macros/sql/generate_series.sql 2022-06-14 04:23:35 normalization > 04:23:24.938492 [debug] [MainThread]: Parsing macros/sql/get_column_values.sql 2022-06-14 04:23:35 normalization > 04:23:24.949364 [debug] [MainThread]: Parsing macros/sql/get_query_results_as_dict.sql 2022-06-14 04:23:35 normalization > 04:23:24.957051 [debug] [MainThread]: Parsing macros/sql/get_relations_by_pattern.sql 2022-06-14 04:23:35 normalization > 04:23:24.965605 [debug] [MainThread]: Parsing macros/sql/get_relations_by_prefix.sql 2022-06-14 04:23:35 normalization > 04:23:24.974493 [debug] [MainThread]: Parsing macros/sql/get_table_types_sql.sql 2022-06-14 04:23:35 normalization > 04:23:24.983256 [debug] [MainThread]: Parsing macros/sql/get_tables_by_pattern_sql.sql 2022-06-14 04:23:35 normalization > 04:23:24.994922 [debug] [MainThread]: Parsing macros/sql/get_tables_by_prefix_sql.sql 2022-06-14 04:23:35 normalization > 04:23:25.002419 [debug] [MainThread]: Parsing macros/sql/groupby.sql 2022-06-14 04:23:35 normalization > 04:23:25.009723 [debug] [MainThread]: Parsing macros/sql/haversine_distance.sql 2022-06-14 04:23:35 normalization > 04:23:25.020993 [debug] [MainThread]: Parsing macros/sql/nullcheck.sql 2022-06-14 04:23:35 normalization > 04:23:25.028196 [debug] [MainThread]: Parsing macros/sql/nullcheck_table.sql 2022-06-14 04:23:35 normalization > 04:23:25.035959 [debug] [MainThread]: Parsing macros/sql/pivot.sql 2022-06-14 04:23:35 normalization > 04:23:25.045687 [debug] [MainThread]: Parsing macros/sql/safe_add.sql 2022-06-14 04:23:35 normalization > 04:23:25.052878 [debug] [MainThread]: Parsing macros/sql/star.sql 2022-06-14 04:23:35 normalization > 04:23:25.063352 [debug] [MainThread]: Parsing macros/sql/surrogate_key.sql 2022-06-14 04:23:35 normalization > 04:23:25.072771 [debug] [MainThread]: Parsing macros/sql/union.sql 2022-06-14 04:23:35 normalization > 04:23:25.088715 [debug] [MainThread]: Parsing macros/sql/unpivot.sql 2022-06-14 04:23:35 normalization > 04:23:25.102200 [debug] [MainThread]: Parsing macros/web/get_url_host.sql 2022-06-14 04:23:35 normalization > 04:23:25.109592 [debug] [MainThread]: Parsing macros/web/get_url_parameter.sql 2022-06-14 04:23:35 normalization > 04:23:25.117187 [debug] [MainThread]: Parsing macros/web/get_url_path.sql 2022-06-14 04:23:35 normalization > 04:23:25.580140 [debug] [MainThread]: 1603: static parser failed on generated/airbyte_ctes/MY_SCHEMA/MYTABLE_AB2.sql 2022-06-14 04:23:35 normalization > 04:23:25.631993 [debug] [MainThread]: 1602: parser fallback to jinja rendering on generated/airbyte_ctes/MY_SCHEMA/MYTABLE_AB2.sql 2022-06-14 04:23:35 normalization > 04:23:25.640724 [debug] [MainThread]: 1603: static parser failed on generated/airbyte_ctes/MY_SCHEMA/MYTABLE_AB1.sql 2022-06-14 04:23:35 normalization > 04:23:25.676318 [debug] [MainThread]: 1602: parser fallback to jinja rendering on generated/airbyte_ctes/MY_SCHEMA/MYTABLE_AB1.sql 2022-06-14 04:23:35 normalization > 04:23:25.683967 [debug] [MainThread]: 1603: static parser failed on generated/airbyte_incremental/scd/MY_SCHEMA/MY_TABLE_SCD.sql 2022-06-14 04:23:35 normalization > 04:23:25.717714 [debug] [MainThread]: 1602: parser fallback to jinja rendering on generated/airbyte_incremental/scd/MY_SCHEMA/MY_TABLE_SCD.sql 2022-06-14 04:23:35 normalization > 04:23:25.725681 [debug] [MainThread]: 1603: static parser failed on generated/airbyte_incremental/MY_SCHEMA/MYTABLE.sql 2022-06-14 04:23:35 normalization > 04:23:25.737564 [debug] [MainThread]: 1602: parser fallback to jinja rendering on generated/airbyte_incremental/MY_SCHEMA/MYTABLE.sql 2022-06-14 04:23:35 normalization > 04:23:25.743861 [debug] [MainThread]: 1603: static parser failed on generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql 2022-06-14 04:23:35 normalization > 04:23:25.764361 [debug] [MainThread]: 1602: parser fallback to jinja rendering on generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql 2022-06-14 04:23:35 normalization > 04:23:25.932929 [warn ] [MainThread]: [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources. 2022-06-14 04:23:35 normalization > There are 1 unused configuration paths: 2022-06-14 04:23:35 normalization > - models.airbyte_utils.generated.airbyte_tables 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > 04:23:26.009358 [info ] [MainThread]: Found 5 models, 0 tests, 0 snapshots, 0 analyses, 535 macros, 0 operations, 0 seed files, 1 source, 0 exposures, 0 metrics 2022-06-14 04:23:35 normalization > 04:23:26.015814 [info ] [MainThread]: 2022-06-14 04:23:35 normalization > 04:23:26.021869 [debug] [MainThread]: Acquiring new snowflake connection "master" 2022-06-14 04:23:35 normalization > 04:23:26.028135 [debug] [ThreadPool]: Acquiring new snowflake connection "list_MY_DB" 2022-06-14 04:23:35 normalization > 04:23:26.028814 [debug] [ThreadPool]: Acquiring new snowflake connection "list_MY_DB" 2022-06-14 04:23:35 normalization > 04:23:26.047968 [debug] [ThreadPool]: Using snowflake connection "list_MY_DB" 2022-06-14 04:23:35 normalization > 04:23:26.050678 [debug] [ThreadPool]: Using snowflake connection "list_MY_DB" 2022-06-14 04:23:35 normalization > 04:23:26.056169 [debug] [ThreadPool]: On list_MY_DB: /* {"app": "dbt", "dbt_version": "1.0.0", "profile_name": "normalize", "target_name": "prod", "connection_name": "list_MY_DB"} */ 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > show terse schemas in database "MY_DB" 2022-06-14 04:23:35 normalization > limit 10000 2022-06-14 04:23:35 normalization > 04:23:26.061419 [debug] [ThreadPool]: On list_MY_DB: /* {"app": "dbt", "dbt_version": "1.0.0", "profile_name": "normalize", "target_name": "prod", "connection_name": "list_MY_DB"} */ 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > show terse schemas in database "MY_DB" 2022-06-14 04:23:35 normalization > limit 10000 2022-06-14 04:23:35 normalization > 04:23:26.066340 [debug] [ThreadPool]: Opening a new connection, currently in state init 2022-06-14 04:23:35 normalization > 04:23:26.071092 [debug] [ThreadPool]: Opening a new connection, currently in state init 2022-06-14 04:23:35 normalization > 04:23:27.367778 [debug] [ThreadPool]: SQL status: SUCCESS 55 in 1.3 seconds 2022-06-14 04:23:35 normalization > 04:23:27.371931 [debug] [ThreadPool]: On list_MY_DB: Close 2022-06-14 04:23:35 normalization > 04:23:27.388717 [debug] [ThreadPool]: SQL status: SUCCESS 55 in 1.32 seconds 2022-06-14 04:23:35 normalization > 04:23:27.396928 [debug] [ThreadPool]: On list_MY_DB: Close 2022-06-14 04:23:35 normalization > 04:23:27.583152 [debug] [ThreadPool]: Acquiring new snowflake connection "create_MY_DB__AIRBYTE_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:27.589895 [debug] [ThreadPool]: Acquiring new snowflake connection "create_MY_DB__AIRBYTE_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:27.594917 [debug] [ThreadPool]: Creating schema "_ReferenceKey(database='MY_DB', schema='_airbyte_MY_SCHEMA', identifier=None)" 2022-06-14 04:23:35 normalization > 04:23:27.607802 [debug] [ThreadPool]: Using snowflake connection "create_MY_DB__AIRBYTE_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:27.614130 [debug] [ThreadPool]: On create_MY_DB__AIRBYTE_MY_SCHEMA: /* {"app": "dbt", "dbt_version": "1.0.0", "profile_name": "normalize", "target_name": "prod", "connection_name": "create_MY_DB__AIRBYTE_MY_SCHEMA"} */ 2022-06-14 04:23:35 normalization > create schema if not exists "MY_DB"._AIRBYTE_MY_SCHEMA 2022-06-14 04:23:35 normalization > 04:23:27.619151 [debug] [ThreadPool]: Opening a new connection, currently in state closed 2022-06-14 04:23:35 normalization > 04:23:28.391558 [debug] [ThreadPool]: SQL status: SUCCESS 1 in 0.77 seconds 2022-06-14 04:23:35 normalization > 04:23:28.398112 [debug] [ThreadPool]: On create_MY_DB__AIRBYTE_MY_SCHEMA: Close 2022-06-14 04:23:35 normalization > 04:23:28.581011 [debug] [ThreadPool]: Acquiring new snowflake connection "list_MY_DB_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:28.581570 [debug] [ThreadPool]: Acquiring new snowflake connection "list_MY_DB__AIRBYTE_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:28.594851 [debug] [ThreadPool]: Using snowflake connection "list_MY_DB_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:28.597518 [debug] [ThreadPool]: Using snowflake connection "list_MY_DB__AIRBYTE_MY_SCHEMA" 2022-06-14 04:23:35 normalization > 04:23:28.602827 [debug] [ThreadPool]: On list_MY_DB_MY_SCHEMA: /* {"app": "dbt", "dbt_version": "1.0.0", "profile_name": "normalize", "target_name": "prod", "connection_name": "list_MY_DB_MY_SCHEMA"} */ 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > show terse objects in "MY_DB".MY_SCHEMA 2022-06-14 04:23:35 normalization > 04:23:28.608390 [debug] [ThreadPool]: On list_MY_DB__AIRBYTE_MY_SCHEMA: /* {"app": "dbt", "dbt_version": "1.0.0", "profile_name": "normalize", "target_name": "prod", "connection_name": "list_MY_DB__AIRBYTE_MY_SCHEMA"} */ 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > show terse objects in "MY_DB"._AIRBYTE_MY_SCHEMA 2022-06-14 04:23:35 normalization > 04:23:28.613824 [debug] [ThreadPool]: Opening a new connection, currently in state closed 2022-06-14 04:23:35 normalization > 04:23:28.619188 [debug] [ThreadPool]: Opening a new connection, currently in state closed 2022-06-14 04:23:35 normalization > 04:23:29.712446 [debug] [ThreadPool]: SQL status: SUCCESS 0 in 1.09 seconds 2022-06-14 04:23:35 normalization > 04:23:29.719620 [debug] [ThreadPool]: On list_MY_DB__AIRBYTE_MY_SCHEMA: Close 2022-06-14 04:23:35 normalization > 04:23:29.764040 [debug] [ThreadPool]: SQL status: SUCCESS 1 in 1.15 seconds 2022-06-14 04:23:35 normalization > 04:23:29.771986 [debug] [ThreadPool]: On list_MY_DB_MY_SCHEMA: Close 2022-06-14 04:23:35 normalization > 04:23:29.959272 [info ] [MainThread]: Concurrency: 5 threads (target='prod') 2022-06-14 04:23:35 normalization > 04:23:29.965022 [info ] [MainThread]: 2022-06-14 04:23:35 normalization > 04:23:29.989753 [debug] [Thread-1 ]: Began running node model.airbyte_utils.MYTABLE_AB1 2022-06-14 04:23:35 normalization > 04:23:29.995795 [debug] [Thread-1 ]: Acquiring new snowflake connection "model.airbyte_utils.MYTABLE_AB1" 2022-06-14 04:23:35 normalization > 04:23:30.002412 [debug] [Thread-1 ]: Began compiling node model.airbyte_utils.MYTABLE_AB1 2022-06-14 04:23:35 normalization > 04:23:30.007527 [debug] [Thread-1 ]: Compiling model.airbyte_utils.MYTABLE_AB1 2022-06-14 04:23:35 normalization > 04:23:30.035392 [debug] [Thread-1 ]: Writing injected SQL for node "model.airbyte_utils.MYTABLE_AB1" 2022-06-14 04:23:35 normalization > 04:23:30.091063 [debug] [Thread-1 ]: finished collecting timing info 2022-06-14 04:23:35 normalization > 04:23:30.097028 [debug] [Thread-1 ]: Finished running node model.airbyte_utils.MYTABLE_AB1 2022-06-14 04:23:35 normalization > 04:23:30.107362 [debug] [Thread-3 ]: Began running node model.airbyte_utils.MYTABLE_AB2 2022-06-14 04:23:35 normalization > 04:23:30.113420 [debug] [Thread-3 ]: Acquiring new snowflake connection "model.airbyte_utils.MYTABLE_AB2" 2022-06-14 04:23:35 normalization > 04:23:30.118847 [debug] [Thread-3 ]: Began compiling node model.airbyte_utils.MYTABLE_AB2 2022-06-14 04:23:35 normalization > 04:23:30.124416 [debug] [Thread-3 ]: Compiling model.airbyte_utils.MYTABLE_AB2 2022-06-14 04:23:35 normalization > 04:23:30.170835 [debug] [Thread-3 ]: Writing injected SQL for node "model.airbyte_utils.MYTABLE_AB2" 2022-06-14 04:23:35 normalization > 04:23:30.189230 [debug] [Thread-3 ]: finished collecting timing info 2022-06-14 04:23:35 normalization > 04:23:30.195414 [debug] [Thread-3 ]: Finished running node model.airbyte_utils.MYTABLE_AB2 2022-06-14 04:23:35 normalization > 04:23:30.202530 [debug] [Thread-5 ]: Began running node model.airbyte_utils.MY_TABLE_STG 2022-06-14 04:23:35 normalization > 04:23:30.208449 [info ] [Thread-5 ]: 1 of 3 START view model _AIRBYTE_MY_SCHEMA.MY_TABLE_STG.......................................................... [RUN] 2022-06-14 04:23:35 normalization > 04:23:30.215012 [debug] [Thread-5 ]: Acquiring new snowflake connection "model.airbyte_utils.MY_TABLE_STG" 2022-06-14 04:23:35 normalization > 04:23:30.220595 [debug] [Thread-5 ]: Began compiling node model.airbyte_utils.MY_TABLE_STG 2022-06-14 04:23:35 normalization > 04:23:30.226806 [debug] [Thread-5 ]: Compiling model.airbyte_utils.MY_TABLE_STG 2022-06-14 04:23:35 normalization > 04:23:30.284213 [debug] [Thread-5 ]: Writing injected SQL for node "model.airbyte_utils.MY_TABLE_STG" 2022-06-14 04:23:35 normalization > 04:23:30.314458 [debug] [Thread-5 ]: finished collecting timing info 2022-06-14 04:23:35 normalization > 04:23:30.320274 [debug] [Thread-5 ]: Began executing node model.airbyte_utils.MY_TABLE_STG 2022-06-14 04:23:35 normalization > 04:23:30.354773 [debug] [Thread-5 ]: Writing runtime SQL for node "model.airbyte_utils.MY_TABLE_STG" 2022-06-14 04:23:35 normalization > 04:23:30.414616 [debug] [Thread-5 ]: Using snowflake connection "model.airbyte_utils.MY_TABLE_STG" 2022-06-14 04:23:35 normalization > 04:23:30.420675 [debug] [Thread-5 ]: On model.airbyte_utils.MY_TABLE_STG: /* {"app": "dbt", "dbt_version": "1.0.0", "profile_name": "normalize", "target_name": "prod", "node_id": "model.airbyte_utils.MY_TABLE_STG"} */ 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > create or replace view "MY_DB"._AIRBYTE_MY_SCHEMA."MY_TABLE_STG" 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > as ( 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > with __dbt__cte__MYTABLE_AB1 as ( 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > -- SQL model to parse JSON blob stored in a single column and extract into separated field columns as described by the JSON Schema 2022-06-14 04:23:35 normalization > -- depends_on: "MY_DB".MY_SCHEMA._AIRBYTE_RAW_MY_TABLE 2022-06-14 04:23:35 normalization > select 2022-06-14 04:23:35 normalization > to_varchar(get_path(parse_json(_airbyte_data), '"_width"')) as _WIDTH, ... 2022-06-14 04:23:35 normalization > to_varchar(get_path(parse_json(_airbyte_data), '"_ab_cdc_deleted_at"')) as _AB_CDC_DELETED_AT, 2022-06-14 04:23:35 normalization > to_varchar(get_path(parse_json(_airbyte_data), '"_ab_cdc_updated_at"')) as _AB_CDC_UPDATED_AT, 2022-06-14 04:23:35 normalization > _AIRBYTE_AB_ID, 2022-06-14 04:23:35 normalization > _AIRBYTE_EMITTED_AT, 2022-06-14 04:23:35 normalization > convert_timezone('UTC', current_timestamp()) as _AIRBYTE_NORMALIZED_AT 2022-06-14 04:23:35 normalization > from "MY_DB".MY_SCHEMA._AIRBYTE_RAW_MY_TABLE as table_alias 2022-06-14 04:23:35 normalization > -- MY_TABLE 2022-06-14 04:23:35 normalization > where 1 = 1 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > ), __dbt__cte__MYTABLE_AB2 as ( 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > -- SQL model to cast each column to its adequate SQL type converted from the JSON schema type 2022-06-14 04:23:35 normalization > -- depends_on: __dbt__cte__MYTABLE_AB1 2022-06-14 04:23:35 normalization > select 2022-06-14 04:23:35 normalization > cast(_WIDTH as ... 2022-06-14 04:23:35 normalization > cast(_AB_CDC_UPDATED_AT as 2022-06-14 04:23:35 normalization > varchar 2022-06-14 04:23:35 normalization > ) as _AB_CDC_UPDATED_AT, 2022-06-14 04:23:35 normalization > _AIRBYTE_AB_ID, 2022-06-14 04:23:35 normalization > _AIRBYTE_EMITTED_AT, 2022-06-14 04:23:35 normalization > convert_timezone('UTC', current_timestamp()) as _AIRBYTE_NORMALIZED_AT 2022-06-14 04:23:35 normalization > from __dbt__cte__MYTABLE_AB1 2022-06-14 04:23:35 normalization > -- MY_TABLE 2022-06-14 04:23:35 normalization > where 1 = 1 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > )-- SQL model to build a hash column based on the values of this record 2022-06-14 04:23:35 normalization > -- depends_on: __dbt__cte__MYTABLE_AB2 2022-06-14 04:23:35 normalization > select 2022-06-14 04:23:35 normalization > md5(cast(coalesce(cast(_WIDTH as 2022-06-14 04:23:35 normalization > varchar ... 2022-06-14 04:23:35 normalization > varchar 2022-06-14 04:23:35 normalization > ), '') || '-' || coalesce(cast(_AB_CDC_DELETED_AT as 2022-06-14 04:23:35 normalization > varchar 2022-06-14 04:23:35 normalization > ), '') || '-' || coalesce(cast(_AB_CDC_UPDATED_AT as 2022-06-14 04:23:35 normalization > varchar 2022-06-14 04:23:35 normalization > ), '') as 2022-06-14 04:23:35 normalization > varchar 2022-06-14 04:23:35 normalization > )) as _AIRBYTE_MYTABLE_HASHID, 2022-06-14 04:23:35 normalization > tmp.* 2022-06-14 04:23:35 normalization > from __dbt__cte__MYTABLE_AB2 tmp 2022-06-14 04:23:35 normalization > -- MY_TABLE 2022-06-14 04:23:35 normalization > where 1 = 1 2022-06-14 04:23:35 normalization > 2022-06-14 04:23:35 normalization > ); 2022-06-14 04:23:35 normalization > 04:23:30.425765 [debug] [Thread-5 ]: Opening a new connection, currently in state init 2022-06-14 04:23:35 normalization > 04:23:31.264880 [debug] [Thread-5 ]: Snowflake adapter: Snowflake query id: 01a4ef27-3201-ad6f-001c-050112734d17 2022-06-14 04:23:35 normalization > 04:23:31.270944 [debug] [Thread-5 ]: Snowflake adapter: Snowflake error: 002003 (42S02): SQL compilation error: 2022-06-14 04:23:35 normalization > Object 'MY_DB.MY_SCHEMA._AIRBYTE_RAW_MY_TABLE' does not exist or not authorized. 2022-06-14 04:23:35 normalization > 04:23:31.278795 [debug] [Thread-5 ]: finished collecting timing info 2022-06-14 04:23:35 normalization > 04:23:31.284188 [debug] [Thread-5 ]: On model.airbyte_utils.MY_TABLE_STG: Close 2022-06-14 04:23:35 normalization > 04:23:31.464162 [debug] [Thread-5 ]: Database Error in model MY_TABLE_STG (models/generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql) 2022-06-14 04:23:35 normalization > 002003 (42S02): SQL compilation error: 2022-06-14 04:23:35 normalization > Object 'MY_DB.MY_SCHEMA._AIRBYTE_RAW_MY_TABLE' does not exist or not authorized. 2022-06-14 04:23:35 normalization > compiled SQL at ../build/run/airbyte_utils/models/generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql 2022-06-14 04:23:35 normalization > 04:23:31.470776 [error] [Thread-5 ]: 1 of 3 ERROR creating view model _AIRBYTE_MY_SCHEMA.MY_TABLE_STG................................................. [ERROR in 1.26s] 2022-06-14 04:23:35 normalization > 04:23:31.476403 [debug] [Thread-5 ]: Finished running node model.airbyte_utils.MY_TABLE_STG 2022-06-14 04:23:35 normalization > 04:23:31.482349 [debug] [Thread-1 ]: Began running node model.airbyte_utils.MY_TABLE_SCD 2022-06-14 04:23:35 normalization > 04:23:31.487896 [info ] [Thread-1 ]: 2 of 3 SKIP relation MY_SCHEMA.MY_TABLE_SCD...................................................................... [SKIP] 2022-06-14 04:23:35 normalization > 04:23:31.494114 [debug] [Thread-1 ]: Finished running node model.airbyte_utils.MY_TABLE_SCD 2022-06-14 04:23:35 normalization > 04:23:31.500404 [debug] [Thread-3 ]: Began running node model.airbyte_utils.MYTABLE 2022-06-14 04:23:35 normalization > 04:23:31.506203 [info ] [Thread-3 ]: 3 of 3 SKIP relation MY_SCHEMA.MY_TABLE.......................................................................... [SKIP] 2022-06-14 04:23:35 normalization > 04:23:31.512083 [debug] [Thread-3 ]: Finished running node model.airbyte_utils.MYTABLE 2022-06-14 04:23:35 normalization > 04:23:31.518556 [debug] [MainThread]: Acquiring new snowflake connection "master" 2022-06-14 04:23:35 normalization > 04:23:31.524584 [info ] [MainThread]: 2022-06-14 04:23:35 normalization > 04:23:31.530060 [info ] [MainThread]: Finished running 1 view model, 2 incremental models in 5.50s. 2022-06-14 04:23:35 normalization > 04:23:31.535166 [debug] [MainThread]: Connection 'master' was properly closed. 2022-06-14 04:23:35 normalization > 04:23:31.541329 [debug] [MainThread]: Connection 'list_MY_DB__AIRBYTE_MY_SCHEMA' was properly closed. 2022-06-14 04:23:35 normalization > 04:23:31.547842 [debug] [MainThread]: Connection 'model.airbyte_utils.MYTABLE_AB1' was properly closed. 2022-06-14 04:23:35 normalization > 04:23:31.553254 [debug] [MainThread]: Connection 'model.airbyte_utils.MYTABLE_AB2' was properly closed. 2022-06-14 04:23:35 normalization > 04:23:31.558974 [debug] [MainThread]: Connection 'model.airbyte_utils.MY_TABLE_STG' was properly closed. 2022-06-14 04:23:35 normalization > 04:23:31.645798 [info ] [MainThread]: 2022-06-14 04:23:35 normalization > 04:23:31.651191 [info ] [MainThread]: Completed with 1 error and 0 warnings: 2022-06-14 04:23:35 normalization > 04:23:31.657018 [info ] [MainThread]: 2022-06-14 04:23:35 normalization > 04:23:31.662645 [error] [MainThread]: Database Error in model MY_TABLE_STG (models/generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql) 2022-06-14 04:23:35 normalization > 04:23:31.669224 [error] [MainThread]: 002003 (42S02): SQL compilation error: 2022-06-14 04:23:35 normalization > 04:23:31.675372 [error] [MainThread]: Object 'MY_DB.MY_SCHEMA._AIRBYTE_RAW_MY_TABLE' does not exist or not authorized. 2022-06-14 04:23:35 normalization > 04:23:31.680791 [error] [MainThread]: compiled SQL at ../build/run/airbyte_utils/models/generated/airbyte_views/MY_SCHEMA/MY_TABLE_STG.sql 2022-06-14 04:23:35 normalization > 04:23:31.686401 [info ] [MainThread]: 2022-06-14 04:23:35 normalization > 04:23:31.693007 [info ] [MainThread]: Done. PASS=0 WARN=0 ERROR=1 SKIP=2 TOTAL=3 2022-06-14 04:23:37 INFO i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$2):161 - Completing future exceptionally... io.airbyte.workers.exception.WorkerException: Normalization Failed. at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:63) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:21) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.lang.Thread.run(Thread.java:833) [?:?] Caused by: io.airbyte.workers.exception.WorkerException: Normalization Failed. at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:60) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] ... 3 more Suppressed: io.airbyte.workers.exception.WorkerException: Normalization process wasn't successful at io.airbyte.workers.normalization.DefaultNormalizationRunner.close(DefaultNormalizationRunner.java:162) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:48) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:21) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.lang.Thread.run(Thread.java:833) [?:?] 2022-06-14 04:23:37 INFO i.a.w.t.TemporalAttemptExecution(get):134 - Stopping cancellation check scheduling... 2022-06-14 04:23:37 INFO i.a.w.t.TemporalUtils(withBackgroundHeartbeat):236 - Stopping temporal heartbeating... 2022-06-14 04:23:37 WARN i.t.i.a.POJOActivityTaskHandler(activityFailureToResult):307 - Activity failure. ActivityId=f5c7b6bb-4376-39de-9bf4-24c396888425, activityType=Normalize, attempt=1 java.lang.RuntimeException: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed. at io.airbyte.workers.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:234) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.normalize(NormalizationActivityImpl.java:75) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at jdk.internal.reflect.GeneratedMethodAccessor479.invoke(Unknown Source) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?] at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityInboundCallsInterceptor.execute(POJOActivityTaskHandler.java:214) ~[temporal-sdk-1.8.1.jar:?] at io.temporal.internal.activity.POJOActivityTaskHandler$POJOActivityImplementation.execute(POJOActivityTaskHandler.java:180) ~[temporal-sdk-1.8.1.jar:?] at io.temporal.internal.activity.POJOActivityTaskHandler.handle(POJOActivityTaskHandler.java:120) ~[temporal-sdk-1.8.1.jar:?] at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:204) ~[temporal-sdk-1.8.1.jar:?] at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:164) ~[temporal-sdk-1.8.1.jar:?] at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.8.1.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] Caused by: io.temporal.serviceclient.CheckedExceptionWrapper: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed. at io.temporal.serviceclient.CheckedExceptionWrapper.wrap(CheckedExceptionWrapper.java:56) ~[temporal-serviceclient-1.8.1.jar:?] at io.temporal.internal.sync.WorkflowInternal.wrap(WorkflowInternal.java:448) ~[temporal-sdk-1.8.1.jar:?] at io.temporal.activity.Activity.wrap(Activity.java:51) ~[temporal-sdk-1.8.1.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:138) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:103) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:229) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] ... 13 more Caused by: java.util.concurrent.ExecutionException: io.airbyte.workers.exception.WorkerException: Normalization Failed. at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[?:?] at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073) ~[?:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.get(TemporalAttemptExecution.java:132) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.sync.NormalizationActivityImpl.lambda$normalize$3(NormalizationActivityImpl.java:103) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalUtils.withBackgroundHeartbeat(TemporalUtils.java:229) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] ... 13 more Caused by: io.airbyte.workers.exception.WorkerException: Normalization Failed. at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:63) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:21) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] ... 1 more Caused by: io.airbyte.workers.exception.WorkerException: Normalization Failed. at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:60) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:21) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] ... 1 more Suppressed: io.airbyte.workers.exception.WorkerException: Normalization process wasn't successful at io.airbyte.workers.normalization.DefaultNormalizationRunner.close(DefaultNormalizationRunner.java:162) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:48) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.general.DefaultNormalizationWorker.run(DefaultNormalizationWorker.java:21) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$2(TemporalAttemptExecution.java:158) ~[io.airbyte-airbyte-workers-0.39.13-alpha.jar:?] at java.lang.Thread.run(Thread.java:833) [?:?]