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

Oracle Multithreading lost data

XMLWordPrintable

    • False
    • None
    • False
    • Critical

      In order to make your issue reports as actionable as possible, please provide the following information, depending on the issue type.

      Bug report

      For bug reports, provide this information, please:

      What Debezium connector do you use and what version?

      1.9.5final

      What is the connector configuration?

      <Your answer>

      What is the captured database version and mode of depoyment?

      (E.g. on-premises, with a specific cloud provider, etc.)

      <Your answer>

      What behaviour do you expect?

      data do not lost

      What behaviour do you see?

      data in kafka lost

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

      (Ideally, also verify with latest Alpha/Beta/CR version)

      I haven't used the latest version

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

      (You might be asked later to provide DEBUG/TRACE level log)

      DEBUG io.debezium.connector.base.ChangeEventQueue - Enqueuing source record 'DataChangeEvent [record=SourceRecord{sourcePartition=

      {server=server_1}, sourceOffset={commit_scn=133193131: 0x001576.0002e5c0.0144 :0:1, transaction_id=null, snapshot_scn=133170505, scn=133193127}} ConnectRecord{topic='server_1.DATABASE.TABLE', kafkaPartition=null, key=Struct{ID=2038}, value=Struct{after=Struct{ID=2038},source=Struct{version=1.9.5.Final,connector=oracle,name=server_1,ts_ms=1670933830000,db=WRINS,schema=DATABASE,table=TABLE,txId=0c001f00eaa00000,scn=133193129,commit_scn=133193131,rowid=AAB/7tAACAAAASEAIC,rs_id= 0x001576.0002e5c0.0144 ,ssn=0,redo_thread=1},op=c,ts_ms=1671112640809}, timestamp=null, headers=ConnectHeaders(headers=)}]'
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:null scn:133193133 rowId:AAB/7tAAAAAAAAAAAA redoSql:set transaction read write;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:TABLE scn:133193133 rowId:AAB/7tAACAAAASEAID redoSql:insert into "DATABASE"."TABLE"("ID") values ('2039');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter handleDataEvent insert into "DATABASE"."TABLE"("ID") values ('2039'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter getTableForDataEvent table name:TABLE scn:133193133 rowId:AAB/7tAACAAAASEAID redoSql:insert into "DATABASE"."TABLE"("ID") values ('2039'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter addToTransaction: getTransactionId is 11002000af350000
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter parseDmlStatement insert into "DATABASE"."TABLE"("ID") values ('2039'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter LogMinerDmlEntry and sql is insert into "DATABASE"."TABLE"("ID") values ('2039');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseInsert and sql is insert into "DATABASE"."TABLE"("ID") values ('2039');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseColumnListClause and sql is  insert into "DATABASE"."TABLE"("ID") values ('2039');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseColumnValuesClause and sql is insert into "DATABASE"."TABLE"("ID") values ('2039');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:null scn:133193133 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug enter  handleCommit table name:null scn:133193133 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enteraccept AAB/7tAACAAAASHAE6
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enter prepareAndDispatch
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enter prepareAndDispatch
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog debug  prepareAndDispatch AAB/7tAACAAAASHAE6
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enter dispatchChangeEvent AAB/7tAACAAAASHAE6
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.base.ChangeEventQueue - Enqueuing source record 'DataChangeEvent [record=SourceRecord{sourcePartition={server=server_1}

      , sourceOffset={commit_scn=133193133: 0x001576.0002e5c4.0010 :0:1, transaction_id=null, snapshot_scn=133170505, scn=133193127}} ConnectRecord{topic='server_1.DATABASE.TABLE', kafkaPartition=null, key=Struct

      {ID=2042}, value=Struct{after=Struct{ID=2042}

      ,source=Struct{version=1.9.5.Final,connector=oracle,name=server_1,ts_ms=1670933830000,db=WRINS,schema=DATABASE,table=TABLE,txId=12001a00ec350000,scn=133193130,commit_scn=133193133,rowid=AAB/7tAACAAAASHAE6,rs_id= 0x001576.0002e5c4.0010 ,ssn=0,redo_thread=1},op=c,ts_ms=1671112640809}, timestamp=null, headers=ConnectHeaders(headers=)}]'
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:null scn:133193133 rowId:AAB/7tAAAAAAAAAAAA redoSql:set transaction read write;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:TABLE scn:133193133 rowId:AAB/7tAACAAAASFAF5 redoSql:insert into "DATABASE"."TABLE"("ID") values ('2036');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter handleDataEvent insert into "DATABASE"."TABLE"("ID") values ('2036'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter getTableForDataEvent table name:TABLE scn:133193133 rowId:AAB/7tAACAAAASFAF5 redoSql:insert into "DATABASE"."TABLE"("ID") values ('2036'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter addToTransaction: getTransactionId is 290013000d350000
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter parseDmlStatement insert into "DATABASE"."TABLE"("ID") values ('2036'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter LogMinerDmlEntry and sql is insert into "DATABASE"."TABLE"("ID") values ('2036');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseInsert and sql is insert into "DATABASE"."TABLE"("ID") values ('2036');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseColumnListClause and sql is  insert into "DATABASE"."TABLE"("ID") values ('2036');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseColumnValuesClause and sql is insert into "DATABASE"."TABLE"("ID") values ('2036');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:null scn:133193134 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug enter  handleCommit table name:null scn:133193134 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enteraccept AAB/7tAACAAAASEAID
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enter prepareAndDispatch
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enter prepareAndDispatch
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog debug  prepareAndDispatch AAB/7tAACAAAASEAID
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.TransactionCommitConsumer - tracelog enter dispatchChangeEvent AAB/7tAACAAAASEAID
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.base.ChangeEventQueue - Enqueuing source record 'DataChangeEvent [record=SourceRecord{sourcePartition=

      {server=server_1}

      , sourceOffset={commit_scn=133193134: 0x001576.0002e5c2.017c :0:1, transaction_id=null, snapshot_scn=133170505, scn=133193127}} ConnectRecord{topic='server_1.DATABASE.TABLE', kafkaPartition=null, key=Struct

      {ID=2039}, value=Struct{after=Struct{ID=2039}

      ,source=Struct{version=1.9.5.Final,connector=oracle,name=server_1,ts_ms=1670933830000,db=WRINS,schema=DATABASE,table=TABLE,txId=11002000af350000,scn=133193133,commit_scn=133193134,rowid=AAB/7tAACAAAASEAID,rs_id= 0x001576.0002e5c2.017c ,ssn=0,redo_thread=1},op=c,ts_ms=1671112640809}, timestamp=null, headers=ConnectHeaders(headers=)}]'
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:null scn:133193134 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug enter  handleCommit table name:null scn:133193134 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug enter  hasCommitAlreadyBeenHandled table name:null scn:133193134 rowId:AAAAAAAAAAAAAAAAAA redoSql:commit;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - Transaction 290013000d350000 has already been processed. Offset Commit SCN CommitScn [redoThreadCommitScns=\{1=io.debezium.connector.oracle.CommitScn$RedoThreadCommitScn@35556859}], Transaction Commit SCN 133193134, Last Seen Commit SCN 133193134.
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:null scn:133193135 rowId:AAB/7tAAAAAAAAAAAA redoSql:set transaction read write;
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog debug: processRow raw info table name:TABLE scn:133193135 rowId:AAB/7tAACAAAASEAIE redoSql:insert into "DATABASE"."TABLE"("ID") values ('2027');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter handleDataEvent insert into "DATABASE"."TABLE"("ID") values ('2027'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter getTableForDataEvent table name:TABLE scn:133193135 rowId:AAB/7tAACAAAASEAIE redoSql:insert into "DATABASE"."TABLE"("ID") values ('2027'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter addToTransaction: getTransactionId is 16001a000d350000
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor - tracelog enter parseDmlStatement insert into "DATABASE"."TABLE"("ID") values ('2027'); 
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter LogMinerDmlEntry and sql is insert into "DATABASE"."TABLE"("ID") values ('2027');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseInsert and sql is insert into "DATABASE"."TABLE"("ID") values ('2027');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseColumnListClause and sql is  insert into "DATABASE"."TABLE"("ID") values ('2027');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.parser.LogMinerDmlParser - tracelog enter parseColumnValuesClause and sql is insert into "DATABASE"."TABLE"("ID") values ('2027');
      2022-12-15 21:57:20.809 [debezium-oracleconnector-server_1-change-event-source-coordinator] DEBUG io.debezium.connector.oracle.logminer.events.LogMinerEventRow - tracelog enter getSqlRedo and ResultSet is oracle.jdbc.driver.ForwardOnlyResultSet@26fe41a5

      How to reproduce the issue using our tutorial deployment?

      Highly concurrent insert data

       

      Feature request or enhancement

       the bug  come from
      Different transactions generate the same :
      handleCommit table name:null scn:133193134
      and then deal with :
      Transaction 290013000d350000 has already been processed.
      Actually it  shouldn't be skipped,but skipped

      Which use case/requirement will be addressed by the proposed feature?

      <Your answer>

      Implementation ideas (optional)

      <Your answer>

            ccranfor@redhat.com Chris Cranford
            henry19 Henry zhu
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: