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

Details

Description

Bug report

What Debezium connector do you use and what version?

What is the connector configuration?

What is the captured database version and mode of depoyment?

What behaviour do you see?

Do you see the same behaviour using the latest relesead Debezium version?

Do you have the connector logs, ideally from start till finish?

Attachments

Activity

People

Dates