Loading...

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 1.4.0.Beta1
Affects Version/s: 1.4.0.Alpha1
Component/s: oracle-connector
Labels:
None

Blocked:
False
Ready:
False
Release Note Text:
Undefined
Git Pull Request:
https://github.com/debezium/debezium-incubator/pull/217
Steps to Reproduce:
Hide

– Start connector:

oc apply -f ./con_src_dad_cdc.yml

– output in connect logs:

2020-11-13 09:17:23,226 INFO The connector will wait for 1s before proceeding (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:23,226 INFO The connector will wait for 1s before proceeding (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,227 INFO Snapshot step 1 - Preparing (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,264 INFO Snapshot step 2 - Determining captured tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,454 INFO Snapshot step 3 - Locking captured tables [INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1] (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,455 INFO Snapshot step 4 - Determining snapshot offset (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,475 INFO Snapshot step 5 - Reading structure of captured tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:30,275 INFO Snapshot step 6 - Persisting schema history (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,685 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'TITLE' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,685 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'ROW_COMMENT' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,685 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'CREATED' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,686 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'MODIFIED' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,714 INFO Snapshot step 7 - Snapshotting data (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,714 INFO Exporting data from table 'INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,714 INFO For table 'INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1' using select statement: 'SELECT * FROM "DADENTW"."KFK_SRC_CASE1" AS OF SCN 202512281528' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,724 INFO Finished exporting 3 records for table 'INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1'; total duration '00:00:00.01' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,725 INFO Snapshot - Final stage (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,725 INFO Snapshot ended with SnapshotResult [status=COMPLETED, offset=OracleOffsetContext [scn=202512281528]] (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,725 INFO Connected metrics set to 'true' (io.debezium.pipeline.metrics.StreamingChangeEventSourceMetrics) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,727 INFO Starting streaming (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,727 INFO Requested thread factory for connector OracleConnector, id = infedad named = transactional-buffer (io.debezium.util.Threads) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,807 WARN [Producer clientId=connector-producer-my-src-cdc-dad-0] Error while fetching metadata with correlation id 4 : {infedad.DADENTW.KFK_SRC_CASE1=LEADER_NOT_AVAILABLE} (org.apache.kafka.clients.NetworkClient) [kafka-producer-network-thread | connector-producer-my-src-cdc-dad-0]2020-11-13 09:17:34,817 INFO AbstractConfig values: (org.apache.kafka.common.config.AbstractConfig) [DistributedHerder-connect-1-1]2020-11-13 09:18:22,870 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:18:22,871 INFO WorkerSourceTask{id=my-src-cdc-dad-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:18:22,915 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Finished commitOffsets successfully in 45 ms (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:19:22,916 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:19:22,916 INFO WorkerSourceTask{id=my-src-cdc-dad-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:19:34,792 INFO AbstractConfig values: (org.apache.kafka.common.config.AbstractConfig) [DistributedHerder-connect-1-1]

– Update Statement in SQL Developer:

UPDATE "DADENTW"."KFK_SRC_CASE1" SET "ROW_COMMENT" = 'update for id 3' WHERE id = 3; COMMIT;

– forced log switch:

exec SYS.do_logswitch;

– output in connect log:

2020-11-13 09:20:08,712 WARN All transactions with first SCN <= 202512306365 will be abandoned, offset: 202512303660 (io.debezium.connector.oracle.logminer.LogMinerHelper) [debezium-oracleconnector-infedad-change-event-source-coordinator] 2020-11-13 09:20:08,713 WARN Following long running transaction 0F00030084860500 will be abandoned and ignored: Transaction{firstScn=202512303665, lastScn=202512303665, redoSqls=[[update "DADENTW"."KFK_SRC_CASE1" set "ROW_COMMENT" = 'update for id 3' where "ID" = '3' and "TITLE" = 'Testfall3' and "ROW_COMMENT" = 'COMMENT for row 3' and "CREATED" = TO_DATE('2020-11-10 21:18:51', 'YYYY-MM-DD HH24:MI:SS') and "MODIFIED" = TO_DATE('2020-11-10 21:18:51', 'YYYY-MM-DD HH24:MI:SS');]]} (io.debezium.connector.oracle.logminer.LogMinerHelper) [debezium-oracleconnector-infedad-change-event-source-coordinator] 2020-11-13 09:20:22,917 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1] 2020-11-13 09:20:22,917 INFO WorkerSourceTask{id=my-src-cdc-dad-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]
Show
– Start connector: oc apply -f ./con_src_dad_cdc.yml – output in connect logs: 2020-11-13 09:17:23,226 INFO The connector will wait for 1s before proceeding (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:23,226 INFO The connector will wait for 1s before proceeding (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,227 INFO Snapshot step 1 - Preparing (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,264 INFO Snapshot step 2 - Determining captured tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,454 INFO Snapshot step 3 - Locking captured tables [INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1] (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,455 INFO Snapshot step 4 - Determining snapshot offset (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:28,475 INFO Snapshot step 5 - Reading structure of captured tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:30,275 INFO Snapshot step 6 - Persisting schema history (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,685 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'TITLE' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,685 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'ROW_COMMENT' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,685 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'CREATED' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,686 INFO JdbcValueConverters returned 'org.apache.kafka.connect.data.SchemaBuilder' for column 'MODIFIED' (io.debezium.connector.oracle.OracleValueConverters) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,714 INFO Snapshot step 7 - Snapshotting data (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,714 INFO Exporting data from table 'INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,714 INFO For table 'INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1' using select statement: 'SELECT * FROM "DADENTW" . "KFK_SRC_CASE1" AS OF SCN 202512281528' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,724 INFO Finished exporting 3 records for table 'INFE01A.SUVANET.CH.DADENTW.KFK_SRC_CASE1' ; total duration '00:00:00.01' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,725 INFO Snapshot - Final stage (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,725 INFO Snapshot ended with SnapshotResult [status=COMPLETED, offset=OracleOffsetContext [scn=202512281528]] (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,725 INFO Connected metrics set to ' true ' (io.debezium.pipeline.metrics.StreamingChangeEventSourceMetrics) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,727 INFO Starting streaming (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,727 INFO Requested thread factory for connector OracleConnector, id = infedad named = transactional-buffer (io.debezium.util.Threads) [debezium-oracleconnector-infedad-change-event-source-coordinator]2020-11-13 09:17:32,807 WARN [Producer clientId=connector-producer-my-src-cdc-dad-0] Error while fetching metadata with correlation id 4 : {infedad.DADENTW.KFK_SRC_CASE1=LEADER_NOT_AVAILABLE} (org.apache.kafka.clients.NetworkClient) [kafka-producer-network-thread | connector-producer-my-src-cdc-dad-0]2020-11-13 09:17:34,817 INFO AbstractConfig values: (org.apache.kafka.common.config.AbstractConfig) [DistributedHerder-connect-1-1]2020-11-13 09:18:22,870 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:18:22,871 INFO WorkerSourceTask{id=my-src-cdc-dad-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:18:22,915 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Finished commitOffsets successfully in 45 ms (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:19:22,916 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:19:22,916 INFO WorkerSourceTask{id=my-src-cdc-dad-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]2020-11-13 09:19:34,792 INFO AbstractConfig values: (org.apache.kafka.common.config.AbstractConfig) [DistributedHerder-connect-1-1] – Update Statement in SQL Developer: UPDATE "DADENTW" . "KFK_SRC_CASE1" SET "ROW_COMMENT" = 'update for id 3' WHERE id = 3; COMMIT; – forced log switch: exec SYS.do_logswitch; – output in connect log: 2020-11-13 09:20:08,712 WARN All transactions with first SCN <= 202512306365 will be abandoned, offset: 202512303660 (io.debezium.connector.oracle.logminer.LogMinerHelper) [debezium-oracleconnector-infedad-change-event-source-coordinator] 2020-11-13 09:20:08,713 WARN Following long running transaction 0F00030084860500 will be abandoned and ignored: Transaction{firstScn=202512303665, lastScn=202512303665, redoSqls=[[update "DADENTW" . "KFK_SRC_CASE1" set "ROW_COMMENT" = 'update for id 3' where "ID" = '3' and "TITLE" = 'Testfall3' and "ROW_COMMENT" = 'COMMENT for row 3' and "CREATED" = TO_DATE( '2020-11-10 21:18:51' , 'YYYY-MM-DD HH24:MI:SS' ) and "MODIFIED" = TO_DATE( '2020-11-10 21:18:51' , 'YYYY-MM-DD HH24:MI:SS' );]]} (io.debezium.connector.oracle.logminer.LogMinerHelper) [debezium-oracleconnector-infedad-change-event-source-coordinator] 2020-11-13 09:20:22,917 INFO WorkerSourceTask{id=my-src-cdc-dad-0} Committing offsets (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1] 2020-11-13 09:20:22,917 INFO WorkerSourceTask{id=my-src-cdc-dad-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask) [SourceTaskOffsetCommitter-1]
Market:

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

After successful start and snapshot, the connector starts with streaming but no changes are emitted to Kafka topics. If finally ends in ORA-1291: missing log file.

Issues:

the connector only reacts on changes in the redo log after a log switch (forced or not forced). Changes in the active log aren't processed
after the log switch, the changes are ignored because changes' SCN is too old
after a few more log switches we end up in ORA-1291 like

Caused by: Error : 1291, Position : 0, Sql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '202512024031', endScn => '202512024031', OPTIONS => DBMS_LOGMNR.DICT_FROM_REDO_LOGS + DBMS_LOGMNR.DDL_DICT_TRACKING + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, OriginalSql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '202512024031', endScn => '202512024031', OPTIONS => DBMS_LOGMNR.DICT_FROM_REDO_LOGS + DBMS_LOGMNR.DDL_DICT_TRACKING + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, Error Msg = ORA-01291: missing logfile
 ORA-06512: at "SYS.DBMS_LOGMNR", line 58
 ORA-06512: at line 1

Our environment is a non CDB btw.

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

con_src_dad_cdc.yml
0.8 kB
2020/11/13 5:56 AM
ORA_DB_config_and_permissions.txt
1 kB
2020/11/13 5:56 AM

is related to

DBZ-2754 Oracle Connector(Using Logminer) with Oracle RDS (v12) does not capture changes

Closed

DBZ-2720 Check whether auto-commit DML operations trigger transaction buffer commits w/LogMiner

Resolved

Details

Description

Attachments

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates