Skip to content

MySQL Connector - Access denied error but completed as successful job sync #4236

New issue

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

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

Already on GitHub? Sign in to your account

Closed
danieldiamond opened this issue Jun 21, 2021 · 8 comments

Comments

@danieldiamond
Copy link
Contributor

Expected Behavior

If the credentials for a MySQL source no longer have permissions to access the source database, the job sync should fail.

Current Behavior

The job sync receives an error

Cannot create PoolableConnectionFactory (Access denied...

and yet the job concludes as a successful job sync.

Logs

Uploading logs-1243-0.txt…

Steps to Reproduce

  1. Create MySQL source with working credentials
  2. Create destination and run sync
  3. Remove user from source database and rerun sync

Severity of the bug for you

Medium

Airbyte Version

v0.26.1-alpha

Connector Version (if applicable)

MySQL 0.3.7
Snowflake 0.3.9

Additional context

Environment, version, integration...

@danieldiamond danieldiamond added the type/bug Something isn't working label Jun 21, 2021
@davinchia davinchia added area/connectors Connector related issues priority/high High priority labels Jun 23, 2021
@davinchia
Copy link
Contributor

@marcosmarxm @sherifnada this is pretty important. Have you guys seen other instances of this?

@davinchia
Copy link
Contributor

@jrhizor and I are seeing instances for snowflake where the sync job actually fails with the following error but the job is still marked as successful.

2021-06-23 03:00:27 INFO 2021-06-23 03:00:27 �[32mINFO�[m i.a.i.d.j.c.s.S3StreamCopier(removeFileAndDropTmpTable):181 - {} - Begin cleaning _airbyte_1624417208755__airbyte_raw_tiny_table tmp table in destination.
2021-06-23 03:00:27 INFO 2021-06-23 03:00:27 �[1;31mERROR�[m i.a.i.d.b.BufferedStreamConsumer(close):203 - {} - on close failed.
2021-06-23 03:00:27 INFO net.snowflake.client.jdbc.SnowflakeSQLException: SQL compilation error:
2021-06-23 03:00:27 INFO Schema 'PORTER_TEST_DB.PUBLIC' does not exist or not authorized.
2021-06-23 03:00:27 INFO at net.snowflake.client.jdbc.SnowflakeUtil.checkErrorAndThrowExceptionSub(SnowflakeUtil.java:124) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.jdbc.SnowflakeUtil.checkErrorAndThrowException(SnowflakeUtil.java:64) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.core.StmtUtil.pollForOutput(StmtUtil.java:434) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.core.StmtUtil.execute(StmtUtil.java:338) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.core.SFStatement.executeHelper(SFStatement.java:501) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.core.SFStatement.executeQueryInternal(SFStatement.java:229) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.core.SFStatement.executeQuery(SFStatement.java:167) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.core.SFStatement.execute(SFStatement.java:749) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.jdbc.SnowflakeStatementV1.executeInternal(SnowflakeStatementV1.java:292) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:27 INFO at net.snowflake.client.jdbc.SnowflakeStatementV1.execute(SnowflakeStatementV1.java:342) ~[snowflake-jdbc-3.12.14.jar:3.12.14]
2021-06-23 03:00:28 INFO at io.airbyte.db.jdbc.JdbcDatabase.lambda$execute$0(JdbcDatabase.java:50) ~[io.airbyte-airbyte-db-0.24.7-alpha.jar:?]
2021-06-23 03:00:28 INFO at io.airbyte.db.jdbc.DefaultJdbcDatabase.execute(DefaultJdbcDatabase.java:61) ~[io.airbyte-airbyte-db-0.24.7-alpha.jar:?]
2021-06-23 03:00:28 INFO at io.airbyte.db.jdbc.JdbcDatabase.execute(JdbcDatabase.java:50) ~[io.airbyte-airbyte-db-0.24.7-alpha.jar:?]

@davinchia
Copy link
Contributor

Second bug we found: check connection succeeds even though the wrong warehouse is added.

@marcosmarxm
Copy link
Member

@danieldiamond is possible to set a local csv/json and try to reproduce the error with other destination? Just to validate is a error with Snowflake.

@danieldiamond
Copy link
Contributor Author

danieldiamond commented Jul 5, 2021

Unable to find logs from original job. but running into same issue but the root cause is different now. CDC job appears to be successful but is not picking up new data...

  • Airbyte version: 0.26.4-alpha
  • OS Version / Instance: AWS EC2
  • Deployment: Docker
  • Source Connector and version: source-mysql:0.3.9
  • Destination Connector and version: destination-snowflake:0.3.9
  • Severity: Extreme
  • Step where error happened: Job Sync

Description

This is a CDC job. It was running successfully for a few days, then the credentials were removed so it correctly failed Incorrect username or password was specified.
The scheduled syncs failed over a few days. Now we have reconfigured the credentials and rerun the sync. However it does not appear to be syncing any new data, which there definitely is.

LOG
2021-07-05 00:34:20 INFO () WorkerRun(call):62 - Executing worker wrapper. Airbyte version: 0.26.4-alpha
2021-07-05 00:34:20 INFO () TemporalAttemptExecution(get):110 - Executing worker wrapper. Airbyte version: 0.26.4-alpha
2021-07-05 00:34:20 INFO () DefaultReplicationWorker(run):102 - start sync worker. job id: 1585 attempt id: 0
2021-07-05 00:34:20 INFO () DefaultReplicationWorker(run):111 - configured sync modes: {accounts.address=incremental - append_dedup, accounts.user=incremental - append_dedup}
2021-07-05 00:34:20 INFO () DefaultAirbyteDestination(start):78 - Running destination...
2021-07-05 00:34:20 INFO () LineGobbler(voidCall):85 - Checking if airbyte/destination-snowflake:0.3.9 exists...
2021-07-05 00:34:20 INFO () LineGobbler(voidCall):85 - airbyte/destination-snowflake:0.3.9 was found locally.
2021-07-05 00:34:20 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/1585/0 --network host airbyte/destination-snowflake:0.3.9 write --config destination_config.json --catalog destination_catalog.json
2021-07-05 00:34:20 INFO () LineGobbler(voidCall):85 - Checking if airbyte/source-mysql:0.3.9 exists...
2021-07-05 00:34:20 INFO () LineGobbler(voidCall):85 - airbyte/source-mysql:0.3.9 was found locally.
2021-07-05 00:34:20 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/1585/0 --network host airbyte/source-mysql:0.3.9 read --config source_config.json --catalog source_catalog.json --state input_state.json
2021-07-05 00:34:20 INFO () DefaultReplicationWorker(lambda$getDestinationOutputRunnable$3):243 - Destination output thread started.
2021-07-05 00:34:20 INFO () DefaultReplicationWorker(run):139 - Waiting for source thread to join.
2021-07-05 00:34:20 INFO () DefaultReplicationWorker(lambda$getReplicationRunnable$2):207 - Replication thread started.
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.d.s.SnowflakeDestination(main):81 - {} - starting destination: class io.airbyte.integrations.destination.snowflake.SnowflakeDestination
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):78 - {} - Running integration: io.airbyte.integrations.destination.snowflake.SnowflakeDestination
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationCliParser(parseOptions):135 - {} - integration args: {catalog=destination_catalog.json, write=null, config=destination_config.json}
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):82 - {} - Command: WRITE
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):83 - {} - Integration config: IntegrationConfig{command=WRITE, configPath='destination_config.json', catalogPath='destination_catalog.json', statePath='null'}
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.s.m.MySqlSource(main):312 - {} - starting source: class io.airbyte.integrations.source.mysql.MySqlSource
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):78 - {} - Running integration: io.airbyte.integrations.source.mysql.MySqlSource
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationCliParser(parseOptions):135 - {} - integration args: {read=null, catalog=source_catalog.json, state=input_state.json, config=source_config.json}
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):82 - {} - Command: READ
2021-07-05 00:34:26 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:26 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):83 - {} - Integration config: IntegrationConfig{command=READ, configPath='source_config.json', catalogPath='source_catalog.json', statePath='input_state.json'}
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.d.j.c.SwitchingDestination(getConsumer):83 - {} - Using destination type: INSERT
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(startTracked):120 - {} - class io.airbyte.integrations.destination.buffered_stream_consumer.BufferedStreamConsumer started.
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):145 - {} - Preparing tmp tables in destination started for 2 streams
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):149 - {} - Preparing tmp table in destination started for stream CDC_address. schema: MY_TABLE_CDC, tmp table name: _airbyte_1625445267294__airbyte_raw_CDC_address
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.s.j.JdbcCdcStateManager(<init>):46 - {} - Initialized CDC state with: io.airbyte.integrations.source.jdbc.models.CdcState@45e37a7e[REDACTED]
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.s.j.JdbcStateManager(createCursorInfoForStream):128 - {} - Found matching cursor in state. Stream: AirbyteStreamNameNamespacePair{name='user', namespace='accounts'}. Cursor Field: null Value: null
2021-07-05 00:34:27 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:27 �[32mINFO�[m i.a.i.s.j.JdbcStateManager(createCursorInfoForStream):128 - {} - Found matching cursor in state. Stream: AirbyteStreamNameNamespacePair{name='address', namespace='accounts'}. Cursor Field: null Value: null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.a.i.s.m.MySqlSource(getIncrementalIterators):231 - {} - using CDC: true
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m o.a.k.c.c.AbstractConfig(logAll):354 - {} - EmbeddedConfig values: 
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	access.control.allow.methods = 
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	access.control.allow.origin = 
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	admin.listeners = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	bootstrap.servers = [localhost:9092]
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	client.dns.lookup = use_all_dns_ips
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	config.providers = []
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	connector.client.config.override.policy = None
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	header.converter = class org.apache.kafka.connect.storage.SimpleHeaderConverter
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	internal.key.converter = class org.apache.kafka.connect.json.JsonConverter
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	internal.value.converter = class org.apache.kafka.connect.json.JsonConverter
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	key.converter = class org.apache.kafka.connect.json.JsonConverter
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	listeners = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	metric.reporters = []
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	metrics.num.samples = 2
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	metrics.recording.level = INFO
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	metrics.sample.window.ms = 30000
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	offset.flush.interval.ms = 1000
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	offset.flush.timeout.ms = 5000
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	offset.storage.file.filename = /tmp/cdc-state-offset10848022939682826910/offset.dat
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	offset.storage.partitions = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	offset.storage.replication.factor = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	offset.storage.topic = 
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	plugin.path = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	response.http.headers.config = 
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	rest.advertised.host.name = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	rest.advertised.listener = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	rest.advertised.port = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	rest.extension.classes = []
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	rest.host.name = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	rest.port = 8083
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.cipher.suites = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.client.auth = none
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.enabled.protocols = [TLSv1.2, TLSv1.3]
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.endpoint.identification.algorithm = https
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.engine.factory.class = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.key.password = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.keymanager.algorithm = SunX509
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.keystore.location = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.keystore.password = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.keystore.type = JKS
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.protocol = TLSv1.3
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.provider = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.secure.random.implementation = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.trustmanager.algorithm = PKIX
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.truststore.location = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.truststore.password = null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	ssl.truststore.type = JKS
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	task.shutdown.graceful.timeout.ms = 5000
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	topic.creation.enable = true
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	topic.tracking.allow.reset = true
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	topic.tracking.enable = true
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 	value.converter = class org.apache.kafka.connect.json.JsonConverter
2021-07-05 00:34:30 INFO () JsonSchemaValidator(test):76 - JSON schema validation failed. 
errors: $: unknown found, object expected
2021-07-05 00:34:30 ERROR () DefaultAirbyteStreamFactory(lambda$create$1):83 - Validation failed: null
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m o.a.k.c.r.WorkerConfig(logPluginPathConfigProviderWarning):420 - {} - Variables cannot be used in the 'plugin.path' property, since the property is used by plugin scanning before the config providers that replace the variables are initialized. The raw value 'null' was used for plugin scanning, as opposed to the transformed value 'null', and this may cause unexpected results.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.a.i.s.m.TargetFilePosition(targetFilePosition):64 - {} - Target File position : FileName: mysql-bin-changelog.143359, Position : 758786
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "table.blacklist" is deprecated and will be removed in future versions. Please use "table.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "table.blacklist" is deprecated and will be removed in future versions. Please use "table.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "database.blacklist" is deprecated and will be removed in future versions. Please use "database.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "database.blacklist" is deprecated and will be removed in future versions. Please use "database.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "column.whitelist" is deprecated and will be removed in future versions. Please use "column.include.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "column.blacklist" is deprecated and will be removed in future versions. Please use "column.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "column.whitelist" is deprecated and will be removed in future versions. Please use "column.include.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "column.blacklist" is deprecated and will be removed in future versions. Please use "column.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "column.whitelist" is deprecated and will be removed in future versions. Please use "column.include.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {} - Using configuration property "column.blacklist" is deprecated and will be removed in future versions. Please use "column.exclude.list" instead.
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(start):100 - {} - Starting MySqlConnectorTask with configuration:
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    connector.class = io.debezium.connector.mysql.MySqlConnector
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    snapshot.locking.mode = none
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.history.file.filename = /tmp/cdc-db-history17697130532577346489/dbhistory.dat
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.user = analytics-airbyte
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.dbname = accounts
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    offset.storage = org.apache.kafka.connect.storage.FileOffsetBackingStore
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    boolean.type = io.debezium.connector.mysql.converters.TinyIntOneToBooleanConverter
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.server.name = accounts
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    include.schema.changes = false
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.port = 3306
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    offset.flush.interval.ms = 1000
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    key.converter.schemas.enable = false
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    offset.storage.file.filename = /tmp/cdc-state-offset10848022939682826910/offset.dat
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    decimal.handling.mode = string
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.hostname = auth-stats.cnmsw9njm7zr.us-east-1.rds.amazonaws.com
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.password = ********
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    name = accounts
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    value.converter.schemas.enable = false
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    converters = boolean
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    table.include.list = accounts.address,accounts.user
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    snapshot.mode = initial
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.history = io.airbyte.integrations.source.mysql.FilteredFileDatabaseHistory
2021-07-05 00:34:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:30 �[32mINFO�[m i.d.c.c.BaseSourceTask(lambda$start$0):102 - {} -    database.include.list = accounts
2021-07-05 00:34:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:31 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Using configuration property "database.blacklist" is deprecated and will be removed in future versions. Please use "database.exclude.list" instead.
2021-07-05 00:34:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:31 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Using configuration property "table.blacklist" is deprecated and will be removed in future versions. Please use "table.exclude.list" instead.
2021-07-05 00:34:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:31 �[33mWARN�[m i.d.c.Configuration(lambda$getFallbackStringProperty$34):2135 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Using configuration property "column.blacklist" is deprecated and will be removed in future versions. Please use "column.exclude.list" instead.
2021-07-05 00:34:31 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:31 �[32mINFO�[m i.d.c.m.MySqlConnectorTask(start):82 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Found existing offset: {ts_sec=1625075868, file=mysql-bin-changelog.142124, pos=855950, row=1, server_id=733956844, event=2}
2021-07-05 00:34:32 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:32 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):149 - {} - Preparing tmp table in destination started for stream CDC_user. schema: MY_TABLE_CDC, tmp table name: _airbyte_1625445267305__airbyte_raw_CDC_user
2021-07-05 00:34:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:33 �[32mINFO�[m i.d.c.m.MySqlConnectorTask(isBinlogAvailable):546 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Step 0: Get all known binlogs from MySQL
2021-07-05 00:34:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:33 �[32mINFO�[m i.d.c.m.MySqlConnectorTask(isBinlogAvailable):561 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Connector requires binlog file 'mysql-bin-changelog.142124', but MySQL only has mysql-bin-changelog.143069, mysql-bin-changelog.143070, mysql-bin-changelog.143071, mysql-bin-changelog.143072, mysql-bin-changelog.143073, mysql-bin-changelog.143074, mysql-bin-changelog.143075, mysql-bin-changelog.143076, mysql-bin-changelog.143077, mysql-bin-changelog.143078, mysql-bin-changelog.143079, mysql-bin-changelog.143080, mysql-bin-changelog.143081, mysql-bin-changelog.143082, mysql-bin-changelog.143083, mysql-bin-changelog.143084, mysql-bin-changelog.143085, mysql-bin-changelog.143086, mysql-bin-changelog.143087, mysql-bin-changelog.143088, mysql-bin-changelog.143089, mysql-bin-changelog.143090, mysql-bin-changelog.143091, mysql-bin-changelog.143092, mysql-bin-changelog.143093, mysql-bin-changelog.143094, mysql-bin-changelog.143095, mysql-bin-changelog.143096, mysql-bin-changelog.143097, mysql-bin-changelog.143098, mysql-bin-changelog.143099, mysql-bin-changelog.143100, mysql-bin-changelog.143101, mysql-bin-changelog.143102, mysql-bin-changelog.143103, mysql-bin-changelog.143104, mysql-bin-changelog.143105, mysql-bin-changelog.143106, mysql-bin-changelog.143107, mysql-bin-changelog.143108, mysql-bin-changelog.143109, mysql-bin-changelog.143110, mysql-bin-changelog.143111, mysql-bin-changelog.143112, mysql-bin-changelog.143113, mysql-bin-changelog.143114, mysql-bin-changelog.143115, mysql-bin-changelog.143116, mysql-bin-changelog.143117, mysql-bin-changelog.143118, mysql-bin-changelog.143119, mysql-bin-changelog.143120, mysql-bin-changelog.143121, mysql-bin-changelog.143122, mysql-bin-changelog.143123, mysql-bin-changelog.143124, mysql-bin-changelog.143125, mysql-bin-changelog.143126, mysql-bin-changelog.143127, mysql-bin-changelog.143128, mysql-bin-changelog.143129, mysql-bin-changelog.143130, mysql-bin-changelog.143131, mysql-bin-changelog.143132, mysql-bin-changelog.143133, mysql-bin-changelog.143134, mysql-bin-changelog.143135, mysql-bin-changelog.143136, mysql-bin-changelog.143137, mysql-bin-changelog.143138, mysql-bin-changelog.143139, mysql-bin-changelog.143140, mysql-bin-changelog.143141, mysql-bin-changelog.143142, mysql-bin-changelog.143143, mysql-bin-changelog.143144, mysql-bin-changelog.143145, mysql-bin-changelog.143146, mysql-bin-changelog.143147, mysql-bin-changelog.143148, mysql-bin-changelog.143149, mysql-bin-changelog.143150, mysql-bin-changelog.143151, mysql-bin-changelog.143152, mysql-bin-changelog.143153, mysql-bin-changelog.143154, mysql-bin-changelog.143155, mysql-bin-changelog.143156, mysql-bin-changelog.143157, mysql-bin-changelog.143158, mysql-bin-changelog.143159, mysql-bin-changelog.143160, mysql-bin-changelog.143161, mysql-bin-changelog.143162, mysql-bin-changelog.143163, mysql-bin-changelog.143164, mysql-bin-changelog.143165, mysql-bin-changelog.143166, mysql-bin-changelog.143167, mysql-bin-changelog.143168, mysql-bin-changelog.143169, mysql-bin-changelog.143170, mysql-bin-changelog.143171, mysql-bin-changelog.143172, mysql-bin-changelog.143173, mysql-bin-changelog.143174, mysql-bin-changelog.143175, mysql-bin-changelog.143176, mysql-bin-changelog.143177, mysql-bin-changelog.143178, mysql-bin-changelog.143179, mysql-bin-changelog.143180, mysql-bin-changelog.143181, mysql-bin-changelog.143182, mysql-bin-changelog.143183, mysql-bin-changelog.143184, mysql-bin-changelog.143185, mysql-bin-changelog.143186, mysql-bin-changelog.143187, mysql-bin-changelog.143188, mysql-bin-changelog.143189, mysql-bin-changelog.143190, mysql-bin-changelog.143191, mysql-bin-changelog.143192, mysql-bin-changelog.143193, mysql-bin-changelog.143194, mysql-bin-changelog.143195, mysql-bin-changelog.143196, mysql-bin-changelog.143197, mysql-bin-changelog.143198, mysql-bin-changelog.143199, mysql-bin-changelog.143200, mysql-bin-changelog.143201, mysql-bin-changelog.143202, mysql-bin-changelog.143203, mysql-bin-changelog.143204, mysql-bin-changelog.143205, mysql-bin-changelog.143206, mysql-bin-changelog.143207, mysql-bin-changelog.143208, mysql-bin-changelog.143209, mysql-bin-changelog.143210, mysql-bin-changelog.143211, mysql-bin-changelog.143212, mysql-bin-changelog.143213, mysql-bin-changelog.143214, mysql-bin-changelog.143215, mysql-bin-changelog.143216, mysql-bin-changelog.143217, mysql-bin-changelog.143218, mysql-bin-changelog.143219, mysql-bin-changelog.143220, mysql-bin-changelog.143221, mysql-bin-changelog.143222, mysql-bin-changelog.143223, mysql-bin-changelog.143224, mysql-bin-changelog.143225, mysql-bin-changelog.143226, mysql-bin-changelog.143227, mysql-bin-changelog.143228, mysql-bin-changelog.143229, mysql-bin-changelog.143230, mysql-bin-changelog.143231, mysql-bin-changelog.143232, mysql-bin-changelog.143233, mysql-bin-changelog.143234, mysql-bin-changelog.143235, mysql-bin-changelog.143236, mysql-bin-changelog.143237, mysql-bin-changelog.143238, mysql-bin-changelog.143239, mysql-bin-changelog.143240, mysql-bin-changelog.143241, mysql-bin-changelog.143242, mysql-bin-changelog.143243, mysql-bin-changelog.143244, mysql-bin-changelog.143245, mysql-bin-changelog.143246, mysql-bin-changelog.143247, mysql-bin-changelog.143248, mysql-bin-changelog.143249, mysql-bin-changelog.143250, mysql-bin-changelog.143251, mysql-bin-changelog.143252, mysql-bin-changelog.143253, mysql-bin-changelog.143254, mysql-bin-changelog.143255, mysql-bin-changelog.143256, mysql-bin-changelog.143257, mysql-bin-changelog.143258, mysql-bin-changelog.143259, mysql-bin-changelog.143260, mysql-bin-changelog.143261, mysql-bin-changelog.143262, mysql-bin-changelog.143263, mysql-bin-changelog.143264, mysql-bin-changelog.143265, mysql-bin-changelog.143266, mysql-bin-changelog.143267, mysql-bin-changelog.143268, mysql-bin-changelog.143269, mysql-bin-changelog.143270, mysql-bin-changelog.143271, mysql-bin-changelog.143272, mysql-bin-changelog.143273, mysql-bin-changelog.143274, mysql-bin-changelog.143275, mysql-bin-changelog.143276, mysql-bin-changelog.143277, mysql-bin-changelog.143278, mysql-bin-changelog.143279, mysql-bin-changelog.143280, mysql-bin-changelog.143281, mysql-bin-changelog.143282, mysql-bin-changelog.143283, mysql-bin-changelog.143284, mysql-bin-changelog.143285, mysql-bin-changelog.143286, mysql-bin-changelog.143287, mysql-bin-changelog.143288, mysql-bin-changelog.143289, mysql-bin-changelog.143290, mysql-bin-changelog.143291, mysql-bin-changelog.143292, mysql-bin-changelog.143293, mysql-bin-changelog.143294, mysql-bin-changelog.143295, mysql-bin-changelog.143296, mysql-bin-changelog.143297, mysql-bin-changelog.143298, mysql-bin-changelog.143299, mysql-bin-changelog.143300, mysql-bin-changelog.143301, mysql-bin-changelog.143302, mysql-bin-changelog.143303, mysql-bin-changelog.143304, mysql-bin-changelog.143305, mysql-bin-changelog.143306, mysql-bin-changelog.143307, mysql-bin-changelog.143308, mysql-bin-changelog.143309, mysql-bin-changelog.143310, mysql-bin-changelog.143311, mysql-bin-changelog.143312, mysql-bin-changelog.143313, mysql-bin-changelog.143314, mysql-bin-changelog.143315, mysql-bin-changelog.143316, mysql-bin-changelog.143317, mysql-bin-changelog.143318, mysql-bin-changelog.143319, mysql-bin-changelog.143320, mysql-bin-changelog.143321, mysql-bin-changelog.143322, mysql-bin-changelog.143323, mysql-bin-changelog.143324, mysql-bin-changelog.143325, mysql-bin-changelog.143326, mysql-bin-changelog.143327, mysql-bin-changelog.143328, mysql-bin-changelog.143329, mysql-bin-changelog.143330, mysql-bin-changelog.143331, mysql-bin-changelog.143332, mysql-bin-changelog.143333, mysql-bin-changelog.143334, mysql-bin-changelog.143335, mysql-bin-changelog.143336, mysql-bin-changelog.143337, mysql-bin-changelog.143338, mysql-bin-changelog.143339, mysql-bin-changelog.143340, mysql-bin-changelog.143341, mysql-bin-changelog.143342, mysql-bin-changelog.143343, mysql-bin-changelog.143344, mysql-bin-changelog.143345, mysql-bin-changelog.143346, mysql-bin-changelog.143347, mysql-bin-changelog.143348, mysql-bin-changelog.143349, mysql-bin-changelog.143350, mysql-bin-changelog.143351, mysql-bin-changelog.143352, mysql-bin-changelog.143353, mysql-bin-changelog.143354, mysql-bin-changelog.143355, mysql-bin-changelog.143356, mysql-bin-changelog.143357, mysql-bin-changelog.143358, mysql-bin-changelog.143359
2021-07-05 00:34:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:33 �[32mINFO�[m i.d.c.c.BaseSourceTask(stop):192 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Stopping down connector
2021-07-05 00:34:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:33 �[32mINFO�[m i.d.c.m.MySqlConnectorTask(doStop):453 - {dbz.connectorContext=task, dbz.connectorName=accounts, dbz.connectorType=MySQL} - Stopping MySQL connector task
2021-07-05 00:34:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:33 �[32mINFO�[m i.a.i.s.m.DebeziumRecordPublisher(lambda$start$1):103 - {} - Debezium engine shutdown.
2021-07-05 00:34:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:34:33 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onStartFunction$1):155 - {} - Preparing tables in destination completed.
2021-07-05 00:39:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:30 �[32mINFO�[m i.d.e.EmbeddedEngine(stop):996 - {} - Stopping the embedded engine
2021-07-05 00:39:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:30 �[32mINFO�[m i.a.i.s.j.AbstractJdbcSource(lambda$read$4):193 - {} - Closing database connection pool.
2021-07-05 00:39:30 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:30 �[32mINFO�[m i.a.i.s.j.AbstractJdbcSource(lambda$read$4):195 - {} - Closed database connection pool.
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - Exception in thread "main" java.lang.RuntimeException: java.lang.RuntimeException: org.apache.kafka.connect.errors.ConnectException: The connector is trying to read binlog starting at binlog file 'mysql-bin-changelog.142124', pos=855950, skipping 2 events plus 1 rows, but this is no longer available on the server. Reconfigure the connector to use a snapshot when needed.
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.source.mysql.DebeziumRecordIterator.requestClose(DebeziumRecordIterator.java:143)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.source.mysql.DebeziumRecordIterator.computeNext(DebeziumRecordIterator.java:94)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.source.mysql.DebeziumRecordIterator.computeNext(DebeziumRecordIterator.java:52)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:42)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:58)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.commons.util.CompositeIterator.computeNext(CompositeIterator.java:83)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.commons.util.CompositeIterator.computeNext(CompositeIterator.java:83)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:58)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at java.base/java.util.Iterator.forEachRemaining(Iterator.java:132)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:105)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.source.mysql.MySqlSource.main(MySqlSource.java:313)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - Caused by: java.lang.RuntimeException: org.apache.kafka.connect.errors.ConnectException: The connector is trying to read binlog starting at binlog file 'mysql-bin-changelog.142124', pos=855950, skipping 2 events plus 1 rows, but this is no longer available on the server. Reconfigure the connector to use a snapshot when needed.
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.source.mysql.DebeziumRecordPublisher.close(DebeziumRecordPublisher.java:135)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.commons.concurrency.VoidCallable.call(VoidCallable.java:35)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.airbyte.integrations.source.mysql.DebeziumRecordIterator.requestClose(DebeziumRecordIterator.java:141)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	... 20 more
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - Caused by: org.apache.kafka.connect.errors.ConnectException: The connector is trying to read binlog starting at binlog file 'mysql-bin-changelog.142124', pos=855950, skipping 2 events plus 1 rows, but this is no longer available on the server. Reconfigure the connector to use a snapshot when needed.
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.debezium.connector.mysql.MySqlConnectorTask.start(MySqlConnectorTask.java:132)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:106)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.debezium.embedded.EmbeddedEngine.run(EmbeddedEngine.java:758)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at io.debezium.embedded.ConvertingEngineBuilder$2.run(ConvertingEngineBuilder.java:171)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
2021-07-05 00:39:30 ERROR () LineGobbler(voidCall):85 - 	at java.base/java.lang.Thread.run(Thread.java:832)
2021-07-05 00:39:32 INFO () DefaultReplicationWorker(run):141 - Source thread complete.
2021-07-05 00:39:32 INFO () DefaultReplicationWorker(run):142 - Waiting for destination thread to join.
2021-07-05 00:39:32 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:32 �[32mINFO�[m i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):80 - {} - Airbyte message consumer: succeeded.
2021-07-05 00:39:32 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:32 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(close):190 - {} - executing on success close procedure.
2021-07-05 00:39:32 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:32 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):182 - {} - Finalizing tables in destination started for 2 streams
2021-07-05 00:39:32 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:32 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):187 - {} - Finalizing stream CDC_address. schema MY_TABLE_CDC, tmp table _airbyte_1625445267294__airbyte_raw_CDC_address, final table _airbyte_raw_CDC_address
2021-07-05 00:39:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:33 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):187 - {} - Finalizing stream CDC_user. schema MY_TABLE_CDC, tmp table _airbyte_1625445267305__airbyte_raw_CDC_user, final table _airbyte_raw_CDC_user
2021-07-05 00:39:33 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:33 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):200 - {} - Executing finalization of tables.
2021-07-05 00:39:35 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:35 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):202 - {} - Finalizing tables in destination completed.
2021-07-05 00:39:35 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:35 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):205 - {} - Cleaning tmp tables in destination started for 2 streams
2021-07-05 00:39:35 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:35 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):209 - {} - Cleaning tmp table in destination started for stream CDC_address. schema MY_TABLE_CDC, tmp table name: _airbyte_1625445267294__airbyte_raw_CDC_address
2021-07-05 00:39:36 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:36 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):209 - {} - Cleaning tmp table in destination started for stream CDC_user. schema MY_TABLE_CDC, tmp table name: _airbyte_1625445267305__airbyte_raw_CDC_user
2021-07-05 00:39:36 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:36 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):214 - {} - Cleaning tmp tables in destination completed.
2021-07-05 00:39:36 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:36 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):118 - {} - Completed integration: io.airbyte.integrations.destination.snowflake.SnowflakeDestination
2021-07-05 00:39:36 INFO () DefaultAirbyteStreamFactory(lambda$create$0):73 - 2021-07-05 00:39:36 �[32mINFO�[m i.a.i.d.s.SnowflakeDestination(main):83 - {} - completed destination: class io.airbyte.integrations.destination.snowflake.SnowflakeDestination
2021-07-05 00:39:39 INFO () DefaultReplicationWorker(run):144 - Destination thread complete.
2021-07-05 00:39:39 WARN () DefaultAirbyteSource(close):132 - Source process might not have shut down correctly. source process alive: false, source process exit value: 1. This warning is normal if the job was cancelled.
2021-07-05 00:39:39 INFO () DefaultReplicationWorker(run):169 - sync summary: io.airbyte.config.ReplicationAttemptSummary@334ae58[status=completed,recordsSynced=0,bytesSynced=0,startTime=1625445260596,endTime=1625445579461]
2021-07-05 00:39:39 INFO () DefaultReplicationWorker(run):178 - Source did not output any state messages
2021-07-05 00:39:39 WARN () DefaultReplicationWorker(run):186 - State capture: No new state, falling back on input state: io.airbyte.config.State@67086451[state={"cdc":false,"streams":[<redacted>>
2021-07-05 00:39:39 INFO () TemporalAttemptExecution(get):133 - Stopping cancellation check scheduling...
2021-07-05 00:39:39 INFO () RetryingTemporalAttemptExecution(get):118 - Last output present: true. Should attempt again: false
2021-07-05 00:39:39 INFO () SyncWorkflow$ReplicationActivityImpl(replicate):200 - attempt summaries: [<redacted>]
2021-07-05 00:39:39 INFO () TemporalAttemptExecution(get):110 - Executing worker wrapper. Airbyte version: 0.26.4-alpha
2021-07-05 00:39:39 INFO () DefaultNormalizationWorker(run):61 - Running normalization.
2021-07-05 00:39:39 INFO () LineGobbler(voidCall):85 - Checking if airbyte/normalization:0.1.33 exists...
2021-07-05 00:39:39 INFO () LineGobbler(voidCall):85 - airbyte/normalization:0.1.33 was found locally.
2021-07-05 00:39:39 INFO () DockerProcessFactory(create):127 - Preparing command: docker run --rm --init -i -v airbyte_workspace:/data -v /tmp/airbyte_local:/local -w /data/1585/0/normalize --network host airbyte/normalization:0.1.33 run --integration-type snowflake --config destination_config.json --catalog destination_catalog.json
2021-07-05 00:39:42 INFO () LineGobbler(voidCall):85 - Running: transform-config --config destination_config.json --integration-type snowflake --out /data/1585/0/normalize
2021-07-05 00:39:42 INFO () LineGobbler(voidCall):85 - Namespace(config='destination_config.json', integration_type=<DestinationType.snowflake: 'snowflake'>, out='/data/1585/0/normalize')
2021-07-05 00:39:42 INFO () LineGobbler(voidCall):85 - transform_snowflake
2021-07-05 00:39:42 INFO () LineGobbler(voidCall):85 - Running: transform-catalog --integration-type snowflake --profile-config-dir /data/1585/0/normalize --catalog destination_catalog.json --out /data/1585/0/normalize/models/generated/ --json-column _airbyte_data
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 - Processing destination_catalog.json...
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_ADDRESS_AB1.sql from CDC_address
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_ADDRESS_AB2.sql from CDC_address
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_ADDRESS_AB3.sql from CDC_address
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_ADDRESS_AB4.sql from CDC_address
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_tables/MY_TABLE_CDC/CDC_ADDRESS_SCD.sql from CDC_address
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_tables/MY_TABLE_CDC/CDC_ADDRESS.sql from CDC_address
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_USER_AB1.sql from CDC_user
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_USER_AB2.sql from CDC_user
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_USER_AB3.sql from CDC_user
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_ctes/MY_TABLE_CDC/CDC_USER_AB4.sql from CDC_user
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_tables/MY_TABLE_CDC/CDC_USER_SCD.sql from CDC_user
2021-07-05 00:39:43 INFO () LineGobbler(voidCall):85 -   Generating airbyte_tables/MY_TABLE_CDC/CDC_USER.sql from CDC_user
2021-07-05 00:39:45 INFO () LineGobbler(voidCall):85 - Running with dbt=0.19.1
2021-07-05 00:39:47 INFO () LineGobbler(voidCall):85 - [�[33mWARNING�[0m]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
2021-07-05 00:39:47 INFO () LineGobbler(voidCall):85 - There are 1 unused configuration paths:
2021-07-05 00:39:47 INFO () LineGobbler(voidCall):85 - - models.airbyte_utils.generated.airbyte_views
2021-07-05 00:39:47 INFO () LineGobbler(voidCall):85 - 
2021-07-05 00:39:47 INFO () LineGobbler(voidCall):85 - Found 12 models, 0 tests, 0 snapshots, 0 analyses, 369 macros, 0 operations, 0 seed files, 2 sources, 0 exposures
2021-07-05 00:39:47 INFO () LineGobbler(voidCall):85 - 
2021-07-05 00:39:51 INFO () LineGobbler(voidCall):85 - 00:39:51 | Concurrency: 32 threads (target='prod')
2021-07-05 00:39:51 INFO () LineGobbler(voidCall):85 - 00:39:51 | 
2021-07-05 00:39:52 INFO () LineGobbler(voidCall):85 - 00:39:52 | 1 of 4 START table model MY_TABLE_CDC.CDC_ADDRESS_SCD........................................................ [RUN]
2021-07-05 00:39:52 INFO () LineGobbler(voidCall):85 - 00:39:52 | 2 of 4 START table model MY_TABLE_CDC.CDC_USER_SCD........................................................... [RUN]
2021-07-05 00:40:39 INFO () LineGobbler(voidCall):85 - 00:40:38 | 1 of 4 OK created table model MY_TABLE_CDC.CDC_ADDRESS_SCD................................................... [�[32mSUCCESS 1�[0m in 46.68s]
2021-07-05 00:40:39 INFO () LineGobbler(voidCall):85 - 00:40:39 | 3 of 4 START table model MY_TABLE_CDC.CDC_ADDRESS............................................................ [RUN]
2021-07-05 00:40:46 INFO () LineGobbler(voidCall):85 - 00:40:46 | 3 of 4 OK created table model MY_TABLE_CDC.CDC_ADDRESS....................................................... [�[32mSUCCESS 1�[0m in 7.61s]
2021-07-05 00:41:17 INFO () LineGobbler(voidCall):85 - 00:41:17 | 2 of 4 OK created table model MY_TABLE_CDC.CDC_USER_SCD...................................................... [�[32mSUCCESS 1�[0m in 84.91s]
2021-07-05 00:41:17 INFO () LineGobbler(voidCall):85 - 00:41:17 | 4 of 4 START table model MY_TABLE_CDC.CDC_USER............................................................... [RUN]
2021-07-05 00:41:32 INFO () LineGobbler(voidCall):85 - 00:41:32 | 4 of 4 OK created table model MY_TABLE_CDC.CDC_USER.......................................................... [�[32mSUCCESS 1�[0m in 15.12s]
2021-07-05 00:41:33 INFO () LineGobbler(voidCall):85 - 00:41:33 | 
2021-07-05 00:41:33 INFO () LineGobbler(voidCall):85 - 00:41:33 | Finished running 4 table models in 106.36s.
2021-07-05 00:41:33 INFO () LineGobbler(voidCall):85 - 
2021-07-05 00:41:33 INFO () LineGobbler(voidCall):85 - �[32mCompleted successfully�[0m
2021-07-05 00:41:33 INFO () LineGobbler(voidCall):85 - 
2021-07-05 00:41:33 INFO () LineGobbler(voidCall):85 - Done. PASS=4 WARN=0 ERROR=0 SKIP=0 TOTAL=4
2021-07-05 00:41:36 INFO () DefaultNormalizationWorker(run):76 - Normalization executed in 1.
2021-07-05 00:41:36 INFO () TemporalAttemptExecution(get):133 - Stopping cancellation check scheduling...

@etsybaev
Copy link
Contributor

etsybaev commented Jul 6, 2021

Was able to reproduce the issue
Selection_221
Selection_220

@sherifnada
Copy link
Contributor

closed in #4617

@sherifnada sherifnada added this to the Core - 2021-07-14 milestone Jul 9, 2021
@sherifnada sherifnada assigned sherifnada and unassigned etsybaev Jul 9, 2021
@etsybaev
Copy link
Contributor

etsybaev commented Jul 9, 2021

Re-tested on the latest master using these steps:

  1. Create MySQL source with working credentials
  2. Create destination and run sync
  3. Remove user from source database and rerun sync

The issue is not reproducible anymore
Selection_229

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

7 participants