Uploaded image for project: 'Debezium'
  1. Debezium
  2. DBZ-8923

XStream may fail with invalid processed low-watermark

XMLWordPrintable

      This appeared in a test on the testing farm recently:

      2025-04-11 23:18:23,014 INFO   BlockingSnapshotIT||test  Starting test io.debezium.connector.oracle.BlockingSnapshotIT#executeBlockingSnapshotWhileStreaming   [io.debezium.connector.oracle.BlockingSnapshotIT]
      2025-04-11 23:18:23,047 INFO   BlockingSnapshotIT||test  Database Version: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
      Version 19.3.0.0.0   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:23,048 INFO   BlockingSnapshotIT||test  Loading the custom source info struct maker plugin: io.debezium.connector.oracle.OracleSourceInfoStructMaker   [io.debezium.config.CommonConnectorConfig]
      2025-04-11 23:18:23,735 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:23,748 INFO   BlockingSnapshotIT||engine  Engine state has changed from 'CREATING' to 'INITIALIZING'   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,749 INFO   BlockingSnapshotIT||engine  Loading the custom source info struct maker plugin: io.debezium.connector.oracle.OracleSourceInfoStructMaker   [io.debezium.config.CommonConnectorConfig]
      2025-04-11 23:18:23,790 INFO   BlockingSnapshotIT||engine  Database Version: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
      Version 19.3.0.0.0   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:23,791 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:23,792 INFO   BlockingSnapshotIT||engine  Engine state has changed from 'INITIALIZING' to 'CREATING_TASKS'   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,793 INFO   BlockingSnapshotIT||engine  Engine state has changed from 'CREATING_TASKS' to 'STARTING_TASKS'   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,793 INFO   BlockingSnapshotIT||engine  Waiting max. for 90000 ms for individual source tasks to start.   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,794 INFO   ||  Starting OracleConnectorTask with configuration:
         connector.class = io.debezium.connector.oracle.OracleConnector
         record.processing.shutdown.timeout.ms = 1000
         schema.include.list = DEBEZIUM
         include.schema.changes = false
         record.processing.order = ORDERED
         schema.history.internal.file.filename = /var/ARTIFACTS/work-oraclewhtq1q6a/debezium-testing/tmt/plans/oracle/oracle/discover/default-0/tests/target/data/file-schema-history-connect.txt
         snapshot.database.errors.max.retries = 3
         topic.prefix = server1
         offset.storage.file.filename = /var/ARTIFACTS/work-oraclewhtq1q6a/debezium-testing/tmt/plans/oracle/oracle/discover/default-0/tests/target/data/file-connector-offsets.txt
         signal.data.collection = ORCLPDB1.DEBEZIUM.DEBEZIUM_SIGNAL
         record.processing.threads = 
         database.out.server.name = dbzxout
         errors.retry.delay.initial.ms = 300
         value.converter = org.apache.kafka.connect.json.JsonConverter
         key.converter = org.apache.kafka.connect.json.JsonConverter
         database.admin.hostname = 0.0.0.0
         snapshot.include.collection.list = ORCLPDB1.DEBEZIUM.A
         database.user = c##dbzuser
         database.dbname = ORCLCDB
         offset.storage = org.apache.kafka.connect.storage.FileOffsetBackingStore
         database.connection.adapter = xstream
         database.pdb.name = ORCLPDB1
         offset.flush.timeout.ms = 5000
         errors.retry.delay.max.ms = 10000
         database.port = 1521
         offset.flush.interval.ms = 0
         internal.task.management.timeout.ms = 90000
         schema.history.internal = io.debezium.storage.file.history.FileSchemaHistory
         record.processing.with.serial.consumer = false
         errors.max.retries = -1
         database.hostname = 0.0.0.0
         database.password = ********
         name = testing-connector
         snapshot.mode = initial
         [io.debezium.connector.common.BaseSourceTask]
      2025-04-11 23:18:23,794 INFO   ||  Loading the custom source info struct maker plugin: io.debezium.connector.oracle.OracleSourceInfoStructMaker   [io.debezium.config.CommonConnectorConfig]
      2025-04-11 23:18:23,794 INFO   ||  Loading the custom topic naming strategy plugin: io.debezium.schema.SchemaTopicNamingStrategy   [io.debezium.config.CommonConnectorConfig]
      2025-04-11 23:18:23,819 INFO   ||  Database Version: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
      Version 19.3.0.0.0   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:23,836 INFO   ||  Oracle MAX_STRING_SIZE is STANDARD   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:23,843 INFO   ||  No previous offsets found   [io.debezium.connector.common.BaseSourceTask]
      2025-04-11 23:18:23,867 INFO   ||  Database Version: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
      Version 19.3.0.0.0   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:23,902 INFO   ||  Connector started for the first time.   [io.debezium.connector.common.BaseSourceTask]
      2025-04-11 23:18:23,902 INFO   ||  No previous offset found   [io.debezium.connector.oracle.OracleConnectorTask]
      2025-04-11 23:18:23,902 INFO   ||  Requested thread factory for component OracleConnector, id = server1 named = SignalProcessor   [io.debezium.util.Threads]
      2025-04-11 23:18:23,902 INFO   ||  Requested thread factory for component OracleConnector, id = server1 named = change-event-source-coordinator   [io.debezium.util.Threads]
      2025-04-11 23:18:23,902 INFO   ||  Requested thread factory for component OracleConnector, id = server1 named = blocking-snapshot   [io.debezium.util.Threads]
      2025-04-11 23:18:23,903 INFO   ||  Creating thread debezium-oracleconnector-server1-change-event-source-coordinator   [io.debezium.util.Threads]
      2025-04-11 23:18:23,903 INFO   BlockingSnapshotIT||engine  All tasks have started successfully.   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,903 INFO   BlockingSnapshotIT||engine  Engine state has changed from 'STARTING_TASKS' to 'POLLING_TASKS'   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,903 INFO   BlockingSnapshotIT||engine  Using io.debezium.embedded.async.ParallelSmtConsumerProcessor processor   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:23,904 INFO   Oracle|server1|snapshot  Metrics registered   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:23,904 INFO   Oracle|server1|snapshot  Context created   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:23,904 INFO   Oracle|server1|snapshot  According to the connector configuration both schema and data will be snapshot.   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:23,906 INFO   Oracle|server1|snapshot  Snapshot step 1 - Preparing   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:23,907 INFO   Oracle|server1|snapshot  Snapshot step 2 - Determining captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:24,514 INFO   Oracle|server1|snapshot  Adding table ORCLPDB1.DEBEZIUM.DEBEZIUM_SIGNAL to the list of capture schema tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:24,514 INFO   Oracle|server1|snapshot  Adding table ORCLPDB1.DEBEZIUM.A to the list of capture schema tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:24,514 INFO   Oracle|server1|snapshot  Adding table ORCLPDB1.DEBEZIUM.B to the list of capture schema tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:24,514 INFO   Oracle|server1|snapshot  Created connection pool with 1 threads   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:24,514 INFO   Oracle|server1|snapshot  Snapshot step 3 - Locking captured tables [ORCLPDB1.DEBEZIUM.A]   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:24,515 INFO   Oracle|server1|snapshot  Snapshot step 4 - Determining snapshot offset   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:25,662 INFO   Oracle|server1|snapshot  	Current SCN resolved as 2307663   [io.debezium.connector.oracle.xstream.XStreamAdapter]
      2025-04-11 23:18:25,662 INFO   Oracle|server1|snapshot  Snapshot step 5 - Reading structure of captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:25,663 INFO   Oracle|server1|snapshot  All eligible tables schema should be captured, capturing: [ORCLPDB1.DEBEZIUM.A, ORCLPDB1.DEBEZIUM.B, ORCLPDB1.DEBEZIUM.DEBEZIUM_SIGNAL]   [io.debezium.connector.oracle.OracleSnapshotChangeEventSource]
      2025-04-11 23:18:25,751 INFO   Oracle|server1|snapshot  	Registering 'ORCLPDB1.DEBEZIUM.A' attributes: object_id=73029, data_object_id=73029   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:25,752 INFO   Oracle|server1|snapshot  	Registering 'ORCLPDB1.DEBEZIUM.B' attributes: object_id=73031, data_object_id=73031   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:25,787 INFO   Oracle|server1|snapshot  	Registering 'ORCLPDB1.DEBEZIUM.DEBEZIUM_SIGNAL' attributes: object_id=73033, data_object_id=73033   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:26,329 INFO   Oracle|server1|snapshot  Snapshot step 6 - Persisting schema history   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:26,329 INFO   Oracle|server1|snapshot  Capturing structure of table ORCLPDB1.DEBEZIUM.A   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:27,873 INFO   Oracle|server1|snapshot  Already applied 1 database changes   [io.debezium.relational.history.SchemaHistoryMetrics]
      2025-04-11 23:18:27,873 INFO   Oracle|server1|snapshot  Capturing structure of table ORCLPDB1.DEBEZIUM.B   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:27,964 INFO   Oracle|server1|snapshot  Capturing structure of table ORCLPDB1.DEBEZIUM.DEBEZIUM_SIGNAL   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:28,180 INFO   Oracle|server1|snapshot  Snapshot step 7 - Snapshotting data   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:28,181 INFO   Oracle|server1|snapshot  Creating snapshot worker pool with 1 worker thread(s)   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:28,181 INFO   Oracle|server1|snapshot  For table 'ORCLPDB1.DEBEZIUM.A' using select statement: 'SELECT "PK", "AA" FROM "DEBEZIUM"."A" AS OF SCN 2307663'   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:28,181 INFO   ||  Exporting data from table 'ORCLPDB1.DEBEZIUM.A' (1 of 1 tables)   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:28,200 INFO   ||  	 Finished exporting 1000 records for table 'ORCLPDB1.DEBEZIUM.A' (1 of 1 tables); total duration '00:00:00.019'   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:28,200 INFO   Oracle|server1|snapshot  Snapshot - Final stage   [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
      2025-04-11 23:18:28,209 INFO   Oracle|server1|snapshot  Snapshot completed   [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
      2025-04-11 23:18:28,209 INFO   Oracle|server1|snapshot  Snapshot ended with SnapshotResult [status=COMPLETED, offset=OracleOffsetContext [scn=2307663, commit_scn=[], lcr_position=null]]   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:28,210 INFO   Oracle|server1|streaming  Connected metrics set to 'true'   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:28,236 INFO   Oracle|server1|streaming  Database Version: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
      Version 19.3.0.0.0   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:28,237 INFO   Oracle|server1|streaming  No incremental snapshot in progress, no action needed on start   [io.debezium.pipeline.source.snapshot.incremental.AbstractIncrementalSnapshotChangeEventSource]
      2025-04-11 23:18:28,238 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:28,238 INFO   Oracle|server1|streaming  SignalProcessor started. Scheduling it every 5000ms   [io.debezium.pipeline.signal.SignalProcessor]
      2025-04-11 23:18:28,238 INFO   Oracle|server1|streaming  Creating thread debezium-oracleconnector-server1-SignalProcessor   [io.debezium.util.Threads]
      2025-04-11 23:18:28,239 INFO   Oracle|server1|streaming  Starting streaming   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:28,265 INFO   Oracle|server1|streaming  Database Version: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
      Version 19.3.0.0.0   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:29,916 INFO   ||  1335 records sent during previous 00:00:06.123, last recorded offset of {server=server1} partition is {lcr_position=0000000000233f0c00000001000000010000000000233f0b000000010000000102, snapshot_scn=2307663}   [io.debezium.connector.common.BaseSourceTask]
      2025-04-11 23:18:30,514 INFO   BlockingSnapshotIT||test  Sending signal with query INSERT INTO DEBEZIUM.DEBEZIUM_SIGNAL VALUES('ad-hoc', 'execute-snapshot', '{"type": "BLOCKING","data-collections": ["ORCLPDB1.DEBEZIUM.A"]}')   [io.debezium.connector.oracle.BlockingSnapshotIT]
      2025-04-11 23:18:30,533 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:30,649 INFO   Oracle|server1|streaming  Requested 'BLOCKING' snapshot of data collections '[ORCLPDB1.DEBEZIUM.A]' with additional conditions '[]' and surrogate key 'PK of table will be used'   [io.debezium.pipeline.signal.actions.snapshotting.ExecuteSnapshot]
      2025-04-11 23:18:30,649 INFO   Oracle|server1|streaming  Creating thread debezium-oracleconnector-server1-blocking-snapshot   [io.debezium.util.Threads]
      2025-04-11 23:18:31,774 INFO   Oracle|server1|streaming  Streaming will now pause   [io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource]
      2025-04-11 23:18:31,775 INFO   Oracle|server1|snapshot  Starting snapshot   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:31,801 INFO   Oracle|server1|snapshot  Snapshot step 1 - Preparing   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:31,801 INFO   Oracle|server1|snapshot  Snapshot step 2 - Determining captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:32,065 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:32,418 INFO   Oracle|server1|snapshot  Created connection pool with 1 threads   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:32,418 INFO   Oracle|server1|snapshot  Snapshot step 3 - Locking captured tables [ORCLPDB1.DEBEZIUM.A]   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:32,418 INFO   Oracle|server1|snapshot  Snapshot step 4 - Determining snapshot offset   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:32,419 INFO   Oracle|server1|snapshot  Snapshot step 5 - Reading structure of captured tables   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:32,419 INFO   Oracle|server1|snapshot  All eligible tables schema should be captured, capturing: [ORCLPDB1.DEBEZIUM.A]   [io.debezium.connector.oracle.OracleSnapshotChangeEventSource]
      2025-04-11 23:18:32,527 INFO   Oracle|server1|snapshot  	Registering 'ORCLPDB1.DEBEZIUM.A' attributes: object_id=73029, data_object_id=73029   [io.debezium.connector.oracle.OracleConnection]
      2025-04-11 23:18:33,289 INFO   Oracle|server1|snapshot  Snapshot step 6 - Persisting schema history   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,289 INFO   Oracle|server1|snapshot  Capturing structure of table ORCLPDB1.DEBEZIUM.A   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,895 INFO   Oracle|server1|snapshot  Already applied 4 database changes   [io.debezium.relational.history.SchemaHistoryMetrics]
      2025-04-11 23:18:33,896 INFO   Oracle|server1|snapshot  Snapshot step 7 - Snapshotting data   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,896 INFO   Oracle|server1|snapshot  Creating snapshot worker pool with 1 worker thread(s)   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,896 INFO   Oracle|server1|snapshot  For table 'ORCLPDB1.DEBEZIUM.A' using select statement: 'SELECT "PK", "AA" FROM "DEBEZIUM"."A" AS OF SCN 2311513'   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,896 INFO   ||  Exporting data from table 'ORCLPDB1.DEBEZIUM.A' (1 of 1 tables)   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,912 INFO   ||  	 Finished exporting 1860 records for table 'ORCLPDB1.DEBEZIUM.A' (1 of 1 tables); total duration '00:00:00.016'   [io.debezium.relational.RelationalSnapshotChangeEventSource]
      2025-04-11 23:18:33,912 INFO   Oracle|server1|snapshot  Snapshot - Final stage   [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
      2025-04-11 23:18:33,924 INFO   Oracle|server1|snapshot  Snapshot completed   [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
      2025-04-11 23:18:33,925 INFO   Oracle|server1|snapshot  Snapshot ended with SnapshotResult [status=COMPLETED, offset=OracleOffsetContext [scn=2311513, commit_scn=[], lcr_position=000000000023455900000001000000010000000000234559000000010000000102]]   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:33,925 INFO   Oracle|server1|streaming  Streaming resumed   [io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource]
      2025-04-11 23:18:34,641 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      23:18:34.649 apicurio2025-04-11 23:18:34 INFO <_> [io.apicurio.common.apps.logging.audit.AuditLogService] (executor-thread-2) apicurio.audit action="createArtifact" result="success" src_ip="172.17.0.1" if_exists="RETURN_OR_UPDATE" artifact_type="AVRO" group_id="default" canonical="false" artifact_id="server1.DEBEZIUM.A-value"
      23:18:34.658 apicurio2025-04-11 23:18:34 INFO <_> [io.apicurio.common.apps.logging.audit.AuditLogService] (executor-thread-2) apicurio.audit action="createArtifact" result="success" src_ip="172.17.0.1" if_exists="RETURN_OR_UPDATE" artifact_type="AVRO" group_id="default" canonical="false" artifact_id="server1.DEBEZIUM.A-value"
      23:18:34.803 apicurio2025-04-11 23:18:34 INFO <_> [io.apicurio.common.apps.logging.audit.AuditLogService] (executor-thread-2) apicurio.audit action="createArtifact" result="success" src_ip="172.17.0.1" if_exists="RETURN_OR_UPDATE" artifact_type="AVRO" group_id="default" canonical="false" artifact_id="server1.DEBEZIUM.DEBEZIUM_SIGNAL-value"
      2025-04-11 23:18:35,191 ERROR  Oracle|server1|streaming  Producer failure   [io.debezium.pipeline.ErrorHandler]
      io.debezium.DebeziumException: Couldn't set processed low watermark
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.setWatermark(LcrEventHandler.java:359)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.processLCR(LcrEventHandler.java:89)
      	at oracle.streams.XStreamOut.XStreamOutReceiveLCRCallbackNative(Native Method)
      	at oracle.streams.XStreamOut.receiveLCRCallback(Unknown Source)
      	at io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource.execute(XstreamStreamingChangeEventSource.java:116)
      	at io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource.execute(XstreamStreamingChangeEventSource.java:46)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:324)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:203)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:143)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
      	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
      	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:1583)
      Caused by: oracle.streams.StreamsException: ORA-26876: invalid processed low-watermark (current position=000000000023455900000001000000010000000000234558000000010000000102; new position=000000000023455900000000000000000000000000234559000000000000000002)
      	at oracle.streams.XStreamOut.XStreamOutSetProcessedLowWatermarkNative(Native Method)
      	at oracle.streams.XStreamOut.setProcessedLowWatermark(Unknown Source)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.setWatermark(LcrEventHandler.java:348)
      	... 13 common frames omitted
      2025-04-11 23:18:35,223 ERROR  BlockingSnapshotIT||engine  Engine has failed with    [io.debezium.embedded.async.AsyncEmbeddedEngine]
      java.util.concurrent.ExecutionException: org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.
      	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.embedded.async.AsyncEmbeddedEngine.runTasksPolling(AsyncEmbeddedEngine.java:489)
      	at io.debezium.embedded.async.AsyncEmbeddedEngine.run(AsyncEmbeddedEngine.java:220)
      	at io.debezium.embedded.async.TestingAsyncEmbeddedEngine.run(TestingAsyncEmbeddedEngine.java:29)
      	at io.debezium.embedded.AbstractConnectorTest.lambda$start$8(AbstractConnectorTest.java:453)
      	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:1583)
      Caused by: org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.
      	at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:67)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.processLCR(LcrEventHandler.java:130)
      	at oracle.streams.XStreamOut.XStreamOutReceiveLCRCallbackNative(Native Method)
      	at oracle.streams.XStreamOut.receiveLCRCallback(Unknown Source)
      	at io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource.execute(XstreamStreamingChangeEventSource.java:116)
      	at io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource.execute(XstreamStreamingChangeEventSource.java:46)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:324)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:203)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:143)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
      	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
      	... 3 common frames omitted
      Caused by: io.debezium.DebeziumException: Couldn't set processed low watermark
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.setWatermark(LcrEventHandler.java:359)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.processLCR(LcrEventHandler.java:89)
      	... 12 common frames omitted
      Caused by: oracle.streams.StreamsException: ORA-26876: invalid processed low-watermark (current position=000000000023455900000001000000010000000000234558000000010000000102; new position=000000000023455900000000000000000000000000234559000000000000000002)
      	at oracle.streams.XStreamOut.XStreamOutSetProcessedLowWatermarkNative(Native Method)
      	at oracle.streams.XStreamOut.setProcessedLowWatermark(Unknown Source)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.setWatermark(LcrEventHandler.java:348)
      	... 13 common frames omitted
      2025-04-11 23:18:35,223 INFO   BlockingSnapshotIT||engine  Engine state has changed from 'POLLING_TASKS' to 'STOPPING'   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:35,224 INFO   ||  Stopping down connector   [io.debezium.connector.common.BaseSourceTask]
      2025-04-11 23:18:36,232 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:36,232 INFO   Oracle|server1|streaming  Finished streaming   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:36,232 INFO   Oracle|server1|streaming  Connected metrics set to 'false'   [io.debezium.pipeline.ChangeEventSourceCoordinator]
      2025-04-11 23:18:36,233 INFO   ||  SignalProcessor stopped   [io.debezium.pipeline.signal.SignalProcessor]
      2025-04-11 23:18:36,233 INFO   ||  Debezium ServiceRegistry stopped.   [io.debezium.service.DefaultServiceRegistry]
      2025-04-11 23:18:36,240 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:36,242 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:18:36,243 INFO   BlockingSnapshotIT||engine  Stopped task #1 out of 1 tasks (it took 1019 ms to stop the task).   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:36,243 INFO   BlockingSnapshotIT||engine  Engine is stopped.   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:36,243 INFO   BlockingSnapshotIT||engine  Engine state has changed from 'STOPPING' to 'STOPPED'   [io.debezium.embedded.async.AsyncEmbeddedEngine]
      2025-04-11 23:18:36,243 ERROR  BlockingSnapshotIT||engine  org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.   [io.debezium.connector.oracle.BlockingSnapshotIT]
      org.apache.kafka.connect.errors.ConnectException: An exception occurred in the change event producer. This connector will be stopped.
      	at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:67)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.processLCR(LcrEventHandler.java:130)
      	at oracle.streams.XStreamOut.XStreamOutReceiveLCRCallbackNative(Native Method)
      	at oracle.streams.XStreamOut.receiveLCRCallback(Unknown Source)
      	at io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource.execute(XstreamStreamingChangeEventSource.java:116)
      	at io.debezium.connector.oracle.xstream.XstreamStreamingChangeEventSource.execute(XstreamStreamingChangeEventSource.java:46)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:324)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:203)
      	at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:143)
      	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
      	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
      	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:1583)
      Caused by: io.debezium.DebeziumException: Couldn't set processed low watermark
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.setWatermark(LcrEventHandler.java:359)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.processLCR(LcrEventHandler.java:89)
      	... 12 common frames omitted
      Caused by: oracle.streams.StreamsException: ORA-26876: invalid processed low-watermark (current position=000000000023455900000001000000010000000000234558000000010000000102; new position=000000000023455900000000000000000000000000234559000000000000000002)
      	at oracle.streams.XStreamOut.XStreamOutSetProcessedLowWatermarkNative(Native Method)
      	at oracle.streams.XStreamOut.setProcessedLowWatermark(Unknown Source)
      	at io.debezium.connector.oracle.xstream.LcrEventHandler.setWatermark(LcrEventHandler.java:348)
      	... 13 common frames omitted
      2025-04-11 23:20:35,010 INFO   BlockingSnapshotIT||test  Stopping the connector   [io.debezium.connector.oracle.BlockingSnapshotIT]
      2025-04-11 23:20:35,010 INFO   BlockingSnapshotIT||test  Interrupting the engine   [io.debezium.connector.oracle.BlockingSnapshotIT]
      2025-04-11 23:20:35,246 INFO   ||  Connection gracefully closed   [io.debezium.jdbc.JdbcConnection]
      2025-04-11 23:20:35,246 INFO   BlockingSnapshotIT||test  Stopping the connector   [io.debezium.connector.oracle.BlockingSnapshotIT]
      2025-04-11 23:20:35,247 INFO   BlockingSnapshotIT||test  Test io.debezium.connector.oracle.BlockingSnapshotIT#executeBlockingSnapshotWhileStreaming failed   [io.debezium.connector.oracle.BlockingSnapshotIT]
      

              ccranfor@redhat.com Chris Cranford
              ccranfor@redhat.com Chris Cranford
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: