Skip to content
New issue

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

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

Source Mysql: syncing timeout (fetch size may be ignored) #9784

Open
MahmoudElhalwany opened this issue Jan 25, 2022 · 25 comments
Open

Source Mysql: syncing timeout (fetch size may be ignored) #9784

MahmoudElhalwany opened this issue Jan 25, 2022 · 25 comments
Labels
community connectors/source/mysql frozen Not being actively worked on team/db-dw-sources Backlog for Database and Data Warehouse Sources team type/bug Something isn't working zendesk

Comments

@MahmoudElhalwany
Copy link

MahmoudElhalwany commented Jan 25, 2022

Environment

  • Airbyte version: 0.35.5-alpha
  • OS Version / Instance: Linux
  • Deployment: Kubernetes
  • Source Connector and version: MySQL 0.5.1
  • Destination Connector and version: clickhouse
  • Severity: Critical
  • Step where error happened: Sync job

Current Behavior

time out in syncing

Logs

LOG
2022-01-25 11:48:50 �[44msource�[0m > Exception in thread "main" java.lang.RuntimeException: java.lang.RuntimeException: com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 617,005 milliseconds ago. The last packet sent successfully to the server was 647,334 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
2022-01-25 11:48:50 �[44msource�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.s.r.AbstractDbSource(lambda$read$2):125 - {} - Closed database connection pool.
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.integrations.source.relationaldb.AbstractRelationalDbSource.lambda$queryTable$0(AbstractRelationalDbSource.java:64)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.LazyAutoCloseableIterator.computeNext(LazyAutoCloseableIterator.java:37)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:46)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.integrations.source.relationaldb.StateDecoratingIterator.computeNext(StateDecoratingIterator.java:48)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.integrations.source.relationaldb.StateDecoratingIterator.computeNext(StateDecoratingIterator.java:18)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:46)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.CompositeIterator.computeNext(CompositeIterator.java:63)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
2022-01-25 11:48:50 �[44msource�[0m > 	at java.base/java.util.Iterator.forEachRemaining(Iterator.java:132)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:119)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.integrations.source.mysql.MySqlSource.main(MySqlSource.java:204)
2022-01-25 11:48:50 �[44msource�[0m > Caused by: java.lang.RuntimeException: com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 617,005 milliseconds ago. The last packet sent successfully to the server was 647,334 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.db.jdbc.StreamingJdbcDatabase.query(StreamingJdbcDatabase.java:105)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.db.jdbc.JdbcDatabase.query(JdbcDatabase.java:158)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.integrations.source.relationaldb.AbstractRelationalDbSource.lambda$queryTable$0(AbstractRelationalDbSource.java:61)
2022-01-25 11:48:50 �[44msource�[0m > 	... 30 more
2022-01-25 11:48:50 �[44msource�[0m > Caused by: com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 617,005 milliseconds ago. The last packet sent successfully to the server was 647,334 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:637)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:418)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:1003)
2022-01-25 11:48:50 �[44msource�[0m > 	at org.apache.commons.dbcp2.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:122)
2022-01-25 11:48:50 �[44msource�[0m > 	at org.apache.commons.dbcp2.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:122)
2022-01-25 11:48:50 �[44msource�[0m > 	at io.airbyte.db.jdbc.StreamingJdbcDatabase.query(StreamingJdbcDatabase.java:95)
2022-01-25 11:48:50 �[44msource�[0m > 	... 32 more
2022-01-25 11:48:50 �[44msource�[0m > Caused by: com.mysql.cj.exceptions.CJCommunicationsException: The last packet successfully received from the server was 617,005 milliseconds ago. The last packet sent successfully to the server was 647,334 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
2022-01-25 11:48:50 �[44msource�[0m > 	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
2022-01-25 11:48:50 �[44msource�[0m > 	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
2022-01-25 11:48:50 �[44msource�[0m > 	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
2022-01-25 11:48:50 �[44msource�[0m > 	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
2022-01-25 11:48:50 �[44msource�[0m > 	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.ServerPreparedQuery.readExecuteResult(ServerPreparedQuery.java:419)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.ServerPreparedQuery.serverExecute(ServerPreparedQuery.java:208)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:635)
2022-01-25 11:48:50 �[44msource�[0m > 	... 37 more
2022-01-25 11:48:50 �[44msource�[0m > Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:67)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.ResultsetRowReader.read(ResultsetRowReader.java:71)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.ResultsetRowReader.read(ResultsetRowReader.java:42)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.NativeProtocol.read(NativeProtocol.java:1583)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.BinaryResultsetReader.read(BinaryResultsetReader.java:90)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.BinaryResultsetReader.read(BinaryResultsetReader.java:50)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.NativeProtocol.read(NativeProtocol.java:1596)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.protocol.a.NativeProtocol.readAllResults(NativeProtocol.java:1650)
2022-01-25 11:48:50 �[44msource�[0m > 	at com.mysql.cj.ServerPreparedQuery.readExecuteResult(ServerPreparedQuery.java:389)
2022-01-25 11:48:50 �[44msource�[0m > 	... 39 more
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.b.FailureTrackingAirbyteMessageConsumer(close):60 - Airbyte message consumer: succeeded.
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.b.BufferedStreamConsumer(close):201 - executing on success close procedure.
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):160 - Finalizing tables in destination started for 1 streams
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):165 - Finalizing stream orders. schema salla, tmp table _airbyte_tmp_ifj_orders, final table _airbyte_raw_orders
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):178 - Executing finalization of tables.
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):180 - Finalizing tables in destination completed.
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):183 - Cleaning tmp tables in destination started for 1 streams
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):187 - Cleaning tmp table in destination started for stream orders. schema salla, tmp table name: _airbyte_tmp_ifj_orders
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.d.j.JdbcBufferedConsumerFactory(lambda$onCloseFunction$3):192 - Cleaning tmp tables in destination completed.
2022-01-25 11:48:50 �[43mdestination�[0m > 2022-01-25 11:48:50 �[32mINFO�[m i.a.i.b.IntegrationRunner(run):133 - Completed integration: io.airbyte.integrations.base.ssh.SshWrappedDestination

@MahmoudElhalwany MahmoudElhalwany added needs-triage type/bug Something isn't working labels Jan 25, 2022
@harshithmullapudi harshithmullapudi changed the title Mysql syncing timeout Source Mysql: syncing timeout Jan 25, 2022
@harshithmullapudi
Copy link
Contributor

harshithmullapudi commented Jan 25, 2022

Hey @MahmoudElhalwany have you tried changing some config on Mysql db end and see if you can increase the connection time limit ?

@MahmoudElhalwany
Copy link
Author

n increase the connection time limit ?

I have tried that, and it take 23 hours then it gives me the same error

@bleonard bleonard added autoteam team/tse Technical Support Engineers labels Apr 26, 2022
@grishick grishick added team/databases and removed needs-triage team/tse Technical Support Engineers autoteam area/connectors Connector related issues labels Jul 1, 2022
@jorge-gt3
Copy link

@MahmoudElhalwany were you able to get around this issue? I am running into the same problem and tried a few JDBC params, but no luck.

@marcosmarxm
Copy link
Member

Zendesk ticket #1737 has been linked to this issue.

@marcosmarxm
Copy link
Member

Comment made from Zendesk by Sajarin on 2022-08-01 at 18:25:

Hi @ayyoub, this looks to be a known issue with the MySQL source connector when trying to sync with millions of records with high variance in record size: #9784. Feel free to follow the discussion and contribute a fix if you're able to.

@marcosmarxm
Copy link
Member

Comment made from Zendesk by Marcos Marx on 2022-08-02 at 01:58:

@sajarin so this issue still not solved ? because for different table that has 1 millions it runs properly, maybe this is an anomaly

[Discourse post]

@marcosmarxm
Copy link
Member

Comment made from Zendesk by Sajarin on 2022-08-03 at 16:17:

@ayyoub, I don't believe there's a solution yet, it's a bit difficult to reproduce since it only seems to happen with large syncs and many rows. Sometimes it works for some tables but not for others. Could you share some more information about the resources you've allocated for your airbyte instance? Could you also share some information about the differences between the tables that have synced properly and the tables that haven't properly? Furthermore, it may be possible to divide up the full refresh sync into multiple connectors, each syncing a few tables, all to the same destination. Have you considered this route?

@jorge-gt3
Copy link

Let me know if there is anything I can do to help solve this issue. We are able to replicate it consistently. We are able to pull over a million records from small tables, but the moment we tap on a large table, the process fails randomly with the same error. We've tried updating server timeouts and JDBC parameters, and we have seen the job takes longer to fail, but still fails with the same error.

image

here is the stack trace from our log...

	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:46)
	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at io.airbyte.integrations.source.relationaldb.StateDecoratingIterator.computeNext(StateDecoratingIterator.java:53)
	at io.airbyte.integrations.source.relationaldb.StateDecoratingIterator.computeNext(StateDecoratingIterator.java:19)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:46)
	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at io.airbyte.commons.util.CompositeIterator.computeNext(CompositeIterator.java:63)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at io.airbyte.commons.util.DefaultAutoCloseableIterator.computeNext(DefaultAutoCloseableIterator.java:38)
	at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:146)
	at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:141)
	at java.base/java.util.Iterator.forEachRemaining(Iterator.java:132)
	at io.airbyte.integrations.base.IntegrationRunner.lambda$produceMessages$0(IntegrationRunner.java:157)
	at io.airbyte.integrations.base.IntegrationRunner.watchForOrphanThreads(IntegrationRunner.java:207)
	at io.airbyte.integrations.base.IntegrationRunner.produceMessages(IntegrationRunner.java:156)
	at io.airbyte.integrations.base.IntegrationRunner.runInternal(IntegrationRunner.java:137)
	at io.airbyte.integrations.base.IntegrationRunner.run(IntegrationRunner.java:97)
	at io.airbyte.integrations.source.mysql.MySqlSource.main(MySqlSource.java:211)
Caused by: java.lang.RuntimeException: com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 7,281,139 milliseconds ago. The last packet sent successfully to the server was 7,281,201 milliseconds ago.
	at io.airbyte.db.jdbc.StreamingJdbcDatabase.unsafeQuery(StreamingJdbcDatabase.java:75)
	at io.airbyte.db.jdbc.JdbcDatabase.unsafeQuery(JdbcDatabase.java:195)
	at io.airbyte.integrations.source.relationaldb.AbstractRelationalDbSource.lambda$queryTable$0(AbstractRelationalDbSource.java:61)
	... 34 more
Caused by: com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 7,281,139 milliseconds ago. The last packet sent successfully to the server was 7,281,201 milliseconds ago.
	at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
	at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:633)
	at com.mysql.cj.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:417)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:1009)
	at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
	at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
	at io.airbyte.db.jdbc.StreamingJdbcDatabase.unsafeQuery(StreamingJdbcDatabase.java:65)
	... 36 more
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure
The last packet successfully received from the server was 7,281,139 milliseconds ago. The last packet sent successfully to the server was 7,281,201 milliseconds ago.
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
	at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
	at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167)
	at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:520)
	at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:700)
	at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:639)
	at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:137)
	at com.mysql.cj.NativeSession.sendCommand(NativeSession.java:279)
	at com.mysql.cj.ServerPreparedQuery.sendExecutePacket(ServerPreparedQuery.java:378)
	at com.mysql.cj.ServerPreparedQuery.serverExecute(ServerPreparedQuery.java:210)
	at com.mysql.cj.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:631)
	... 41 more
Caused by: java.net.SocketException: Connection reset
	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:323)
	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
	at java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:478)
	at java.base/sun.security.ssl.SSLSocketInputRecord.readHeader(SSLSocketInputRecord.java:472)
	at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:70)
	at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1455)
	at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:1059)
	at java.base/java.io.FilterInputStream.read(FilterInputStream.java:132)
	at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:64)
	at com.mysql.cj.protocol.a.SimplePacketReader.readHeaderLocal(SimplePacketReader.java:81)
	at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
	at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52)
	at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41)
	at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54)
	at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44)
	at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:514)
	... 48 more
,retryable=,timestamp=1660300301920], io.airbyte.config.FailureReason@7cab6474[failureOrigin=source,failureType=,internalMessage=io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped!,externalMessage=Something went wrong within the source connector,metadata=io.airbyte.config.Metadata@19c52295[additionalProperties={attemptNumber=2, jobId=47}],stacktrace=java.util.concurrent.CompletionException: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped!
	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:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1589)
Caused by: io.airbyte.workers.general.DefaultReplicationWorker$SourceException: Source cannot be stopped!
	at io.airbyte.workers.general.DefaultReplicationWorker.lambda$getReplicationRunnable$6(DefaultReplicationWorker.java:332)
	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 1. 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:330)
	... 4 more
,retryable=,timestamp=1660300302014]]]

@sajarin
Copy link
Contributor

sajarin commented Aug 12, 2022

@jorge-gt3 could you share how big your large tables are?

@jorge-gt3
Copy link

jorge-gt3 commented Aug 12, 2022

They vary in size. The error above occurred when I added a table with 19,272,203 rows to the connection. I just joined Slack if you want to chat there.

@jorge-gt3
Copy link

jorge-gt3 commented Aug 13, 2022

I took a closer look and it notice the worker chokes right after this entry log:


2022-08-13 15:07:46 source > 2022-08-13 15:07:46 INFO i.a.d.j.s.AdaptiveStreamingQueryConfig(initialize):38 - Set initial fetch size: 10 rows

It looks like setting the fetch size is last thing that happens before it executing the PreparedStatement, which lead me to this old blog post where someone in the comments said that setFetchSize works with Statement but "doesn't seem to work with PreparedStatement"... ¯\_ (ツ)_/¯

@grishick
Copy link
Contributor

We should verify that fetch size actually works based on the previous comment

@grishick grishick changed the title Source Mysql: syncing timeout Source Mysql: syncing timeout (fetch size may be ignored) Aug 26, 2022
@jorge-gt3
Copy link

jorge-gt3 commented Aug 27, 2022

I looked into this a bit more and it seems like it has been a known issue in the MySQL community...

I found this post in SO and I tried using &useCursorFetch=true&defaultFetchSize=1000 in the JDBC parameters, before realizing this is already hardcoded in the connector... https://github.com/airbytehq/airbyte/blob/master/airbyte-integrations/connectors/source-mysql/src/main/java/io/airbyte/integrations/source/mysql/MySqlSource.java#L148

I assume we also need to add java.sql.ResultSet.TYPE_SS_SERVER_CURSOR_FORWARD_ONLY & java.sql.ResultSet.CONCUR_READ_ONLY to the preparedStatement connection as suggested in one of the SO posts..

From the JDBC implementation notes...

"By default, ResultSets are completely retrieved and stored in memory. In most cases this is the most efficient way to operate and, due to the design of the MySQL network protocol, is easier to implement. If you are working with ResultSets that have a large number of rows or large values and cannot allocate heap space in your JVM for the memory required, you can tell the driver to stream the results back one row at a time."

To enable this functionality, create a Statement instance in the following manner:


stmt = conn.createStatement(java.sql.ResultSet.TYPE_FORWARD_ONLY,
              java.sql.ResultSet.CONCUR_READ_ONLY);
stmt.setFetchSize(Integer.MIN_VALUE);

@shiny
Copy link

shiny commented Aug 30, 2022

Sync from mysql to mysql is failed too for large table.
60,000,000 rows in user table and 80,000,000 in order table.

@grishick
Copy link
Contributor

Changing scope to GA

@grishick grishick added the team/db-dw-sources Backlog for Database and Data Warehouse Sources team label Sep 27, 2022
@danieldiamond
Copy link
Contributor

@grishick any updates on this?

@natalyjazzviolin
Copy link
Contributor

@danieldiamond , @grishick is out right now but let me inquire with the engineering team about this!

@bleonard
Copy link
Contributor

bleonard commented Dec 1, 2022

THere looks to be some big changes in this area with this PR https://github.com/airbytehq/airbyte/pull/17236/files
around useCursorFetch and setting the fetchSize to MIN_VALUE. Curious if there are any changes to people with this issue.

@jorge-gt3
Copy link

I finally got a chance to try this again with the latest version of the MySQL source and I was able to sync over 85 million records using the following JDBC parameters:

useCursorFetch=true&defaultFetchSize=1000&autoReconnect=true&validationQuery=SELECT 1&testOnBorrow=true

@misteryeo
Copy link
Contributor

Per discussion with @prateekmukhedkar - we will add this to the docs.

@cnx-lucaspassos
Copy link

@jorge-gt3 curious how it's going with the changes you have made.

I tried the same... the incremental task is looping - like a streaming process. I think this is happening because of the useCursorFetch parameter.

@javiCalvo
Copy link

Hi! Any updates here? I have this issues with a 47 million record table and the JDBC parameters from @jorge-gt3 didn't solve the error 😞

@prateekmukhedkar
Copy link
Contributor

@javiCalvo can you link your Airbyte workspace or preferably the job history where you are seeing this error? Thank you!

@Jordonkopp
Copy link

Jordonkopp commented Nov 14, 2023

As this still seems to be an issue especially with large tables after a lot of trial and error we seem to have found an ideal set of params that helped us. We used @jorge-gt3 's recommendations with some additions as those alone did not solve our problem.

Our setup is as follows:

  • Kubernetes Deployment
  • Airbyte 0.50.1
  • MySQL Source Connector 3.1.7
  • Snowflake Destination Connector 2.1.7 (Any higher this is an unrelated bug)

Our MySQL JDBC URL Params are as follows

socketTimeout=3600000
&wait_timeout=3600000
&connectTimeout=3600000
&netTimeoutForStreamingResults=3600
&tcpKeepAlive=true
&useServerPrepStmts=true
&useCursorFetch=true
&autoReconnect=true
&validationQuery=SELECT 1
&testOnBorrow=true

These timeouts are in milliseconds

socketTimeout
wait_timeout
connectTimeout

These timeouts are in seconds

netTimeoutForStreamingResults

May seem like a bit of overkill, but it seems like somewhere when parallel writes start a connection is opened but is allowed to timeout. Whether thats in the connector code itself or due to our source table having 1.7B+ rows 🤷

Hopefully this helps someone else having the same issue and this saves you days of debugging and trial and error on large tables 😄

I also had made a post in the community slack channel of folks are looking for a solve there.

@bleonard bleonard added the frozen Not being actively worked on label Mar 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
community connectors/source/mysql frozen Not being actively worked on team/db-dw-sources Backlog for Database and Data Warehouse Sources team type/bug Something isn't working zendesk
Projects
None yet
Development

No branches or pull requests