-
Bug
-
Resolution: Done
-
Major
-
None
-
None
-
False
-
None
-
False
Bug report
What Debezium connector do you use and what version?
2.5.0-Final
What is the connector configuration?
Postgres & MySQL
What is the captured database version and mode of depoyment?
On-premise dockerized MySQL 8.2 and PostgreSQL 16.1.
Setting up
In embedded mode, after the connection to the source and target databases was established and the data capture begins, break the source database connection (I just stop the container).
The retry policy is defined with
- errors.max.retries = 8 (for example)
- errors.retry.delay.initial.ms = 5000 (5 sec)
- errors.retry.delay.max.ms = 60000 (1 min)
The exponential delay is then kicking in and the retries are performed.
What behaviour do you expect?
After 8 retries I expect an exception and the data capture process to be interrupted.
What behaviour do you see?
No interruption, the retries keep going after retrying 8 times. I got to 13 retries with 1 minute delay.
Do you see the same behaviour using the latest relesead Debezium version?
Yes
Do you have the connector logs, ideally from start till finish?
2024-01-10 13:25:05,314 ERROR [debezium-postgresconnector-postgres-change-event-source-coordinator] io.debezium.relational.RelationalSnapshotChangeEventSource: Error during snapshot java.util.concurrent.ExecutionException: org.apache.kafka.connect.errors.ConnectException: Failed reading CURRENT_TIMESTAMP from source database at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191) at io.debezium.relational.RelationalSnapshotChangeEventSource.createDataEvents(RelationalSnapshotChangeEventSource.java:467) at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:165) at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:92) at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:253) at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:237) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:189) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:137) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) 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:840) Caused by: org.apache.kafka.connect.errors.ConnectException: Failed reading CURRENT_TIMESTAMP from source database at io.debezium.relational.RelationalSnapshotChangeEventSource.getSnapshotSourceTimestamp(RelationalSnapshotChangeEventSource.java:507) at io.debezium.relational.RelationalSnapshotChangeEventSource.doCreateDataEventsForTable(RelationalSnapshotChangeEventSource.java:543) at io.debezium.relational.RelationalSnapshotChangeEventSource.lambda$createDataEventsForTableCallable$6(RelationalSnapshotChangeEventSource.java:519) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ... 5 common frames omitted Caused by: org.postgresql.util.PSQLException: FATAL: terminating connection due to administrator command at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356) at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413) at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:333) at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:319) at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:295) at org.postgresql.jdbc.PgStatement.executeQuery(PgStatement.java:244) at io.debezium.jdbc.JdbcConnection.queryAndMap(JdbcConnection.java:628) at io.debezium.jdbc.JdbcConnection.queryAndMap(JdbcConnection.java:497) at io.debezium.jdbc.JdbcConnection.getCurrentTimestamp(JdbcConnection.java:265) at io.debezium.relational.RelationalSnapshotChangeEventSource.getSnapshotSourceTimestamp(RelationalSnapshotChangeEventSource.java:499) ... 8 common frames omitted 2024-01-10 13:25:05,316 ERROR [debezium-postgresconnector-postgres-change-event-source-coordinator] io.debezium.relational.RelationalSnapshotChangeEventSource: Error in finally block java.lang.RuntimeException: org.postgresql.util.PSQLException: This connection has been closed. at io.debezium.relational.RelationalSnapshotChangeEventSource.rollbackTransaction(RelationalSnapshotChangeEventSource.java:752) at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:192) at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:92) at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:253) at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:237) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:189) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:137) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) 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:840) Caused by: org.postgresql.util.PSQLException: This connection has been closed. at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:907) at org.postgresql.jdbc.PgConnection.rollback(PgConnection.java:914) at io.debezium.relational.RelationalSnapshotChangeEventSource.rollbackTransaction(RelationalSnapshotChangeEventSource.java:749) ... 11 common frames omitted 2024-01-10 13:25:05,317 INFO [debezium-postgresconnector-postgres-change-event-source-coordinator] io.debezium.pipeline.source.AbstractSnapshotChangeEventSource: Snapshot - Final stage 2024-01-10 13:25:05,317 WARN [debezium-postgresconnector-postgres-change-event-source-coordinator] io.debezium.pipeline.source.AbstractSnapshotChangeEventSource: Snapshot was not completed successfully, it will be re-executed upon connector restart 2024-01-10 13:25:05,317 ERROR [debezium-postgresconnector-postgres-change-event-source-coordinator] io.debezium.pipeline.ErrorHandler: Producer failure io.debezium.DebeziumException: java.lang.RuntimeException: org.postgresql.util.PSQLException: This connection has been closed. at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:101) at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:253) at io.debezium.pipeline.ChangeEventSourceCoordinator.doSnapshot(ChangeEventSourceCoordinator.java:237) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:189) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:137) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) 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:840) Caused by: java.lang.RuntimeException: org.postgresql.util.PSQLException: This connection has been closed. at io.debezium.relational.RelationalSnapshotChangeEventSource.rollbackTransaction(RelationalSnapshotChangeEventSource.java:752) at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:192) at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:92) ... 9 common frames omitted Suppressed: java.util.concurrent.ExecutionException: org.apache.kafka.connect.errors.ConnectException: Failed reading CURRENT_TIMESTAMP from source database at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191) at io.debezium.relational.RelationalSnapshotChangeEventSource.createDataEvents(RelationalSnapshotChangeEventSource.java:467) at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:165) ... 10 common frames omitted Caused by: org.apache.kafka.connect.errors.ConnectException: Failed reading CURRENT_TIMESTAMP from source database at io.debezium.relational.RelationalSnapshotChangeEventSource.getSnapshotSourceTimestamp(RelationalSnapshotChangeEventSource.java:507) at io.debezium.relational.RelationalSnapshotChangeEventSource.doCreateDataEventsForTable(RelationalSnapshotChangeEventSource.java:543) at io.debezium.relational.RelationalSnapshotChangeEventSource.lambda$createDataEventsForTableCallable$6(RelationalSnapshotChangeEventSource.java:519) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ... 5 common frames omitted Caused by: org.postgresql.util.PSQLException: FATAL: terminating connection due to administrator command at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676) at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366) at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356) at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496) at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413) at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:333) at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:319) at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:295) at org.postgresql.jdbc.PgStatement.executeQuery(PgStatement.java:244) at io.debezium.jdbc.JdbcConnection.queryAndMap(JdbcConnection.java:628) at io.debezium.jdbc.JdbcConnection.queryAndMap(JdbcConnection.java:497) at io.debezium.jdbc.JdbcConnection.getCurrentTimestamp(JdbcConnection.java:265) at io.debezium.relational.RelationalSnapshotChangeEventSource.getSnapshotSourceTimestamp(RelationalSnapshotChangeEventSource.java:499) ... 8 common frames omitted Caused by: org.postgresql.util.PSQLException: This connection has been closed. at org.postgresql.jdbc.PgConnection.checkClosed(PgConnection.java:907) at org.postgresql.jdbc.PgConnection.rollback(PgConnection.java:914) at io.debezium.relational.RelationalSnapshotChangeEventSource.rollbackTransaction(RelationalSnapshotChangeEventSource.java:749) ... 11 common frames omitted ... 2024-01-10 13:57:36,947 INFO [pool-1-thread-1] io.debezium.embedded.EmbeddedEngine: Starting connector, attempt 34 2024-01-10 13:57:36,951 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: Stopping down connector 2024-01-10 13:57:36,961 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: Starting PostgresConnectorTask with configuration: 2024-01-10 13:57:36,989 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: connector.class = io.debezium.connector.postgresql.PostgresConnector 2024-01-10 13:57:36,991 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: slot.name = 69912c3f71c84f7baf67527f1949412d 2024-01-10 13:57:36,992 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: publication.name = migrator_postgres_publication 2024-01-10 13:57:36,994 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: include.schema.changes = false 2024-01-10 13:57:36,995 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: schema.history.internal.store.only.captured.tables.ddl = true 2024-01-10 13:57:36,996 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: schema.history.internal.file.filename = /Users/artem.shubovych/Library/Application Support/MongoDB/Relational Migrator/Debezium/69912c3f71c84f7baf67527f1949412d-schema-history-store.dat 2024-01-10 13:57:36,998 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: tombstones.on.delete = false 2024-01-10 13:57:36,999 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: topic.prefix = postgres 2024-01-10 13:57:37,000 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: offset.storage.file.filename = /Users/artem.shubovych/Library/Application Support/MongoDB/Relational Migrator/Debezium/69912c3f71c84f7baf67527f1949412d-offset-store.dat 2024-01-10 13:57:37,001 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: errors.retry.delay.initial.ms = 5000 2024-01-10 13:57:37,003 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: value.converter = org.apache.kafka.connect.json.JsonConverter 2024-01-10 13:57:37,004 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: key.converter = org.apache.kafka.connect.json.JsonConverter 2024-01-10 13:57:37,005 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: publication.autocreate.mode = disabled 2024-01-10 13:57:37,006 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: database.user = postgres 2024-01-10 13:57:37,007 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: database.dbname = postgres 2024-01-10 13:57:37,008 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: offset.storage = org.apache.kafka.connect.storage.FileOffsetBackingStore 2024-01-10 13:57:37,009 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: slot.drop.on.stop = true 2024-01-10 13:57:37,010 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: time.precision.mode = connect 2024-01-10 13:57:37,011 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: errors.retry.delay.max.ms = 60000 2024-01-10 13:57:37,012 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: offset.flush.timeout.ms = 5000 2024-01-10 13:57:37,013 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: event.processing.failure.handling.mode = fail 2024-01-10 13:57:37,014 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: plugin.name = pgoutput 2024-01-10 13:57:37,015 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: offset.flush.interval.ms = 0 2024-01-10 13:57:37,016 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: schema.history.internal = io.debezium.storage.file.history.FileSchemaHistory 2024-01-10 13:57:37,017 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: errors.max.retries = 8 2024-01-10 13:57:37,018 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: database.hostname = 127.0.0.1 2024-01-10 13:57:37,019 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: database.password = ******** 2024-01-10 13:57:37,020 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: name = engine-69912c3f71c84f7baf67527f1949412d 2024-01-10 13:57:37,021 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: table.include.list = ^public.AllOfTheTypes$,^public.Animal$,^public.Cat$,^public.Person$,^public.Pet$,^public.Sloth$,^public.SomeArrayTypes$,^public.arrayjson$,^public.takeorder$ 2024-01-10 13:57:37,022 INFO [pool-1-thread-1] io.debezium.connector.common.BaseSourceTask: snapshot.mode = initial_only 2024-01-10 13:57:37,023 INFO [pool-1-thread-1] io.debezium.config.CommonConnectorConfig: Loading the custom source info struct maker plugin: io.debezium.connector.postgresql.PostgresSourceInfoStructMaker 2024-01-10 13:57:37,028 INFO [pool-1-thread-1] io.debezium.config.CommonConnectorConfig: Loading the custom topic naming strategy plugin: io.debezium.schema.SchemaTopicNamingStrategy 2024-01-10 13:57:37,038 ERROR [pool-1-thread-1] io.debezium.embedded.EmbeddedEngine: Can't start the connector, will retry later... io.debezium.DebeziumException: Couldn't obtain encoding for database postgres at io.debezium.connector.postgresql.connection.PostgresConnection.getDatabaseCharset(PostgresConnection.java:577) at io.debezium.connector.postgresql.PostgresConnectorTask.start(PostgresConnectorTask.java:86) at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:141) at io.debezium.embedded.EmbeddedEngine.handleRetries(EmbeddedEngine.java:672) at io.debezium.embedded.EmbeddedEngine.pollRecords(EmbeddedEngine.java:710) at io.debezium.embedded.EmbeddedEngine.run(EmbeddedEngine.java:475) at io.debezium.embedded.ConvertingEngineBuilder$2.run(ConvertingEngineBuilder.java:229) 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:840) Caused by: org.postgresql.util.PSQLException: Connection to 127.0.0.1:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections. at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:319) at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:247) at org.postgresql.Driver.makeConnection(Driver.java:434) at org.postgresql.Driver.connect(Driver.java:291) at io.debezium.jdbc.JdbcConnection.lambda$patternBasedFactory$1(JdbcConnection.java:243) at io.debezium.jdbc.JdbcConnection$ConnectionFactoryDecorator.connect(JdbcConnection.java:129) at io.debezium.jdbc.JdbcConnection.connection(JdbcConnection.java:875) at io.debezium.jdbc.JdbcConnection.connection(JdbcConnection.java:870) at io.debezium.connector.postgresql.connection.PostgresConnection.getDatabaseCharset(PostgresConnection.java:574) ... 9 common frames omitted Caused by: java.net.ConnectException: Connection refused at java.base/sun.nio.ch.Net.pollConnect(Native Method) at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672) at java.base/sun.nio.ch.NioSocketImpl.timedFinishConnect(NioSocketImpl.java:554) at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:602) at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327) at java.base/java.net.Socket.connect(Socket.java:633) at org.postgresql.core.PGStream.createSocket(PGStream.java:241) at org.postgresql.core.PGStream.<init>(PGStream.java:98) at org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:109) at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:235) ... 18 common frames omitted
- links to
-
RHEA-2024:139598
Red Hat build of Debezium 2.5.4 release
