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

oracle missing CDC data

    XMLWordPrintable

Details

    • False
    • None
    • False

    Description

      i have had streaming working successfully on 10s of millions of rows EXCEPT for 1 row i detected missing (its the row below on tbl14) that never flowed into kafka.

       

      below is the output of 

      select * from v$logmnr_contents where SCN = 527420504803 or XID = '3E000B00B71C4000'  or commit_scn = 527420504803  or start_scn = 527420504803

      (note that the single file from v$archived_log that i added to this manual debugging logmnr session (ie dbms_logmnr.add_logfile) covers first_change#=527420412499 to next_change#=527420611861)

      SCN START_SCN COMMIT_SCN TIMESTAMP START_TIMESTAMP COMMIT_TIMESTAMP XIDUSN XIDSLT XIDSQN XID PXIDUSN PXIDSLT PXIDSQN PXID TX_NAME OPERATION OPERATION_CODE ROLLBACK SEG_OWNER SEG_NAME TABLE_NAME SEG_TYPE SEG_TYPE_NAME TABLE_SPACE ROW_ID USERNAME OS_USERNAME MACHINE_NAME AUDIT_SESSIONID SESSION# SERIAL# SESSION_INFO THREAD# SEQUENCE# RBASQN RBABLK RBABYTE UBAFIL UBABLK UBAREC UBASQN ABS_FILE# REL_FILE# DATA_BLK# DATA_OBJ# DATA_OBJV# DATA_OBJD# SQL_REDO SQL_UNDO RS_ID SSN CSF INFO STATUS REDO_VALUE UNDO_VALUE SAFE_RESUME_SCN CSCN OBJECT_ID EDITION_NAME CLIENT_ID SRC_CON_NAME SRC_CON_ID SRC_CON_UID SRC_CON_DBID SRC_CON_GUID CON_ID
      527420504803     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   START 6 0       0     AALK3MAAAAAAAAAAAA iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122334 208 11 0 0 0 0 0 0 0 0 0 set transaction read write;    0x00a664.0001ddde.00d0  0 0   0 1992674 1992675         iredacted iredacted 3 3867249061 0   1
      527420504803     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl13 (IS IN SCOPE LIST) tbl13 (IS IN SCOPE LIST) 2 TABLE iredacted AALK3MAAxAALJ3sAAH iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122334 208 11 336249 31 6851 29 49 2924012 300187 20 2928076 insert into ...1 row that I redacted iredacted  0x00a664.0001ddde.00d0  7 0   0 1992676 1992677         iredacted iredacted 3 3867249061 0   1
      527420504803     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl1(NOT in table.include.list scope) tbl1(NOT in table.include.list scope) 2 TABLE iredacted AALK3NADsAAEREOAAC iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122344 24 11 336249 45 6851 29 236 1118478 300199 1 2928077 insert into ...1 row that I redacted iredacted  0x00a664.0001dde8.0018  2 0   0 1992678 1992679         iredacted iredacted 3 3867249061 0   1
      527420504803     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl14 (IS IN SCOPE LIST) tbl14 (IS IN SCOPE LIST) 2 TABLE iredacted AALLsiADtAAEAvhAAL iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122345 212 11 336249 47 6851 29 237 1051617 300203 7 2931490 insert into ...1 row that I redacted iredacted  0x00a664.0001dde9.00d4  11 0   0 1992680 1992681         iredacted iredacted 3 3867249061 0   1
      527420504803     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl2(NOT in table.include.list scope) tbl2(NOT in table.include.list scope) 2 TABLE iredacted AALLsjADtAADuVgAA4 iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122350 16 11 336249 54 6851 29 237 976224 300210 1 2931491 insert into ...1 row that I redacted iredacted  0x00a664.0001ddee.0010  56 0   0 1992682 1992683         iredacted iredacted 3 3867249061 0   1
      527420504804     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl3(NOT in table.include.list scope) tbl3(NOT in table.include.list scope) 2 TABLE iredacted AALLsYADtAAEjKkAAO iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122351 268 11 336249 56 6851 29 237 1192612 300214 26 2931480 insert into ...1 row that I redacted iredacted  0x00a664.0001ddef.010c  14 0   0 1992684 1992685         iredacted iredacted 3 3867249061 0   1
      527420504804     2022-09-22 23:31:05     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl4(NOT in table.include.list scope) tbl4(NOT in table.include.list scope) 2 TABLE iredacted AALLsZADsAAIhBmAA0 iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122355 284 11 336249 62 6851 29 236 2232422 300221 1 2931481 insert into ...1 row that I redacted iredacted  0x00a664.0001ddf3.011c  52 0   0 1992686 1992687         iredacted iredacted 3 3867249061 0   1
      527420504895     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl5(NOT in table.include.list scope) tbl5(NOT in table.include.list scope) 2 TABLE iredacted AALK3GADtAAEGKYAAA iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122486 16 11 336249 64 6851 29 237 1073816 300093 5 2928070 insert into ...1 row that I redacted iredacted  0x00a664.0001de76.0010  0 0   0 1992916 1992917         iredacted iredacted 3 3867249061 0   1
      527420504895     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl5(NOT in table.include.list scope) tbl5(NOT in table.include.list scope) 2 TABLE iredacted AALK3GADtAAEGKYAAB iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122495 108 11 336251 12 6851 29 237 1073816 300093 5 2928070 insert into ...1 row that I redacted iredacted  0x00a664.0001de7f.006c  1 0   0 1992918 1992919         iredacted iredacted 3 3867249061 0   1
      527420504959     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl6(NOT in table.include.list scope) tbl6(NOT in table.include.list scope) 2 TABLE iredacted AALKzYAA0AAAqbiAAJ iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122614 372 11 336251 26 6851 29 52 173794 2501494 1 2927832 insert into ...1 row that I redacted iredacted  0x00a664.0001def6.0174  9 0   0 1993030 1993031         iredacted iredacted 3 3867249061 0   1
      527420504959     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl7(NOT in table.include.list scope) tbl7(NOT in table.include.list scope) 2 TABLE iredacted AALKzZADsAAIlitABL iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122617 212 11 336251 29 6851 29 236 2250925 2501516 1 2927833 insert into ...1 row that I redacted iredacted  0x00a664.0001def9.00d4  75 0   0 1993032 1993033         iredacted iredacted 3 3867249061 0   1
      527420504966     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl8(NOT in table.include.list scope) tbl8(NOT in table.include.list scope) 2 TABLE iredacted AALKzaADtAAEGssAAG iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122625 176 11 336251 31 6851 29 237 1076012 2501527 1 2927834 insert into ...1 row that I redacted iredacted  0x00a664.0001df01.00b0  6 0   0 1993040 1993041         iredacted iredacted 3 3867249061 0   1
      527420504966     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INSERT 1 0 iredacted tbl9(NOT in table.include.list scope) tbl9(NOT in table.include.list scope) 2 TABLE iredacted AALKzbADtAAECrgAAd iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122628 24 11 336251 34 6851 29 237 1059552 2501538 1 2927835 insert into ...1 row that I redacted iredacted  0x00a664.0001df04.0018  29 0   0 1993042 1993043         iredacted iredacted 3 3867249061 0   1
      527420504971     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   UPDATE 3 0 iredacted tbl10(NOT in table.include.list scope) tbl10(NOT in table.include.list scope) 2 TABLE iredacted AALK7AACiAAAetmAAv iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122630 92 11 0 0 0 11 162 125798 300089 1 2928320 update ...1 row that I redacted iredacted  0x00a664.0001df06.005c  0 0   0 1993044 1993045         iredacted iredacted 3 3867249061 0   1
      527420504974     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INTERNAL 0 0       0     AALK6/ADtAACTvkAAG iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122631 276 11 0 0 0 11 237 605156 300081 25 2928319      0x00a664.0001df07.0114  0 0   0 1993046 1993047         iredacted iredacted 3 3867249061 0   1
      527420504974     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   UPDATE 3 0 iredacted tbl11(NOT in table.include.list scope) tbl11(NOT in table.include.list scope) 2 TABLE iredacted AALK6/ADtAACTvkAAG iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122632 48 11 336251 37 6851 11 237 605156 300081 25 2928319 update ...1 row that I redacted --> but only first half of the sql iredacted  0x00a664.0001df08.0030  0 1   0 1993048 1993049         iredacted iredacted 3 3867249061 0   1
      527420504974     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   UPDATE 3 0 iredacted tbl11(NOT in table.include.list scope) tbl11(NOT in table.include.list scope) 2 TABLE iredacted AALK6/ADtAACTvkAAG iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122632 48 11 336251 37 6851 11 237 605156 300081 25 2928319 seems to be continuation of the update in the row above --> second half of the sql iredacted  0x00a664.0001df08.0030  0 0   0 1993048 1993049         iredacted iredacted 3 3867249061 0   1
      527420505067     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   INTERNAL 0 0       0     AALIXPAApAAFUXHAAB iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122819 16 11 0 0 0 11 41 1394119 1202453 14 2917839      0x00a664.0001dfc3.0010  0 0   0 1993196 1993197         iredacted iredacted 3 3867249061 0   1
      527420505067     2022-09-22 23:31:06     62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   UPDATE 3 0 iredacted tbl12(NOT in table.include.list scope) tbl12(NOT in table.include.list scope) 2 TABLE iredacted AALIXPAApAAFUXHAAB iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122820 148 11 336251 41 6851 11 41 1394119 1202453 14 2917839 update ...1 row that I redacted iredacted  0x00a664.0001dfc4.0094  0 0   0 1993200 1993201         iredacted iredacted 3 3867249061 0   1
      527420505068 527420504803 527420505068 2022-09-22 23:31:06 2022-09-22 23:31:05 2022-09-22 23:31:06 62 11 4201655 3E000B00B71C4000 62 11 4201655 3E000B00B71C4000   COMMIT 7 0       0     AAAAAAAAAAAAAAAAAA iredacted iredacted iredacted 144537975 858 9887 iredacted 1 1 42596 122822 156 11 0 0 0 11 0 0 0 0 0 commit;    0x00a664.0001dfc6.009c  0 0   0 1993206 1993207 527420503383 527420505068     iredacted iredacted 3 3867249061 0   1

       

      here are some of my logs around this time:

      {"log":"[2022-09-22 13:29:06,956] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:29:06.956634929Z"}
{"log":"[2022-09-22 13:29:16,956] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:29:16.956760058Z"}
{"log":"[2022-09-22 13:29:17,373] DEBUG Fetching results for SCN [527420496100, 527420498997] (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:29:17.373780576Z"}
{"log":"[2022-09-22 13:29:17,965] DEBUG Counters{rows=514, stuckCount=1, dmlCount=2, ddlCount=0, insertCount=0, updateCount=2, deleteCount=0, commitCount=256, rollbackCount=0, tableMetadataCount=0}. (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:29:17.965237288Z"}
{"log":"[2022-09-22 13:29:17,965] DEBUG Processed in 337 ms. Lag: 1963. Offset SCN: 527420478800, Offset Commit SCN: CommitScn [redoThreadCommitScns={1=RedoThreadCommitScn{thread=1, commitScn=527420498693, rsId=' 0x00a664.0001bcec.019c ', ssn=0}}], Active Transactions: 2, Sleep: 57000 (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:29:17.965262121Z"}
{"log":"[2022-09-22 13:29:26,956] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:29:26.956905539Z"}
{"log":"[2022-09-22 13:29:36,959] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:29:36.960003736Z"}
{"log":"[2022-09-22 13:29:46,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:29:46.960193Z"}
{"log":"[2022-09-22 13:29:56,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:29:56.960336974Z"}
{"log":"[2022-09-22 13:30:06,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:30:06.960483009Z"}
{"log":"[2022-09-22 13:30:15,043] DEBUG Fetching results for SCN [527420498976, 527420501897] (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:30:15.043967881Z"}
{"log":"[2022-09-22 13:30:15,683] DEBUG Counters{rows=651, stuckCount=0, dmlCount=0, ddlCount=0, insertCount=0, updateCount=0, deleteCount=0, commitCount=326, rollbackCount=0, tableMetadataCount=0}. (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:30:15.683283049Z"}
{"log":"[2022-09-22 13:30:15,683] DEBUG Processed in 388 ms. Lag: 2682. Offset SCN: 527420478800, Offset Commit SCN: CommitScn [redoThreadCommitScns={1=RedoThreadCommitScn{thread=1, commitScn=527420498693, rsId=' 0x00a664.0001bcec.019c ', ssn=0}}], Active Transactions: 1, Sleep: 60000 (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:30:15.683308822Z"}
{"log":"[2022-09-22 13:30:16,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:30:16.960618883Z"}
{"log":"[2022-09-22 13:30:26,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:30:26.960790143Z"}
{"log":"[2022-09-22 13:30:36,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:30:36.960945266Z"}
{"log":"[2022-09-22 13:30:46,960] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:30:46.961078138Z"}
{"log":"[2022-09-22 13:30:56,961] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:30:56.961220353Z"}
{"log":"[2022-09-22 13:31:06,961] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:31:06.961368459Z"}
{"log":"[2022-09-22 13:31:15,760] DEBUG Fetching results for SCN [527420501883, 527420505755] (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:31:15.760370781Z"}
{"log":"[2022-09-22 13:31:16,635] INFO [Producer clientId=connector-producer-kafka-connect-safsrc-01-0] Resetting the last seen epoch of partition tbl13-0 to 0 since the associated topicId changed from null to redact1 (org.apache.kafka.clients.Metadata)\n","stream":"stdout","time":"2022-09-22T13:31:16.635501469Z"}
{"log":"[2022-09-22 13:31:16,682] INFO [Producer clientId=connector-producer-kafka-connect-safsrc-01-0] Resetting the last seen epoch of partition tbl14-0 to 0 since the associated topicId changed from null to redact2 (org.apache.kafka.clients.Metadata)\n","stream":"stdout","time":"2022-09-22T13:31:16.682380667Z"}
{"log":"[2022-09-22 13:31:16,682] INFO [Producer clientId=connector-producer-kafka-connect-safsrc-01-0] Resetting the last seen epoch of partition tbl14-2 to 0 since the associated topicId changed from null to redact2 (org.apache.kafka.clients.Metadata)\n","stream":"stdout","time":"2022-09-22T13:31:16.682405793Z"}
{"log":"[2022-09-22 13:31:16,682] INFO [Producer clientId=connector-producer-kafka-connect-safsrc-01-0] Resetting the last seen epoch of partition tbl14-1 to 0 since the associated topicId changed from null to redact2 (org.apache.kafka.clients.Metadata)\n","stream":"stdout","time":"2022-09-22T13:31:16.682408378Z"}
{"log":"[2022-09-22 13:31:16,779] DEBUG Transaction 3e000b00b71c4000 has already been processed. Offset Commit SCN CommitScn [redoThreadCommitScns={1=RedoThreadCommitScn{thread=1, commitScn=527420505068, rsId=' 0x00a664.0001dfc5.01d4 ', ssn=0}}], Transaction Commit SCN 527420505068, Last Seen Commit SCN 527420505068. (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:31:16.779324686Z"}
{"log":"[2022-09-22 13:31:16,923] DEBUG Counters{rows=1196, stuckCount=0, dmlCount=116, ddlCount=0, insertCount=116, updateCount=0, deleteCount=0, commitCount=539, rollbackCount=0, tableMetadataCount=0}. (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:31:16.924102663Z"}
{"log":"[2022-09-22 13:31:16,923] DEBUG Processed in 909 ms. Lag: 2922. Offset SCN: 527420501474, Offset Commit SCN: CommitScn [redoThreadCommitScns={1=RedoThreadCommitScn{thread=1, commitScn=527420505189, rsId=' 0x00a664.0001e077.00f0 ', ssn=0}}], Active Transactions: 1, Sleep: 57000 (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:31:16.924116311Z"}
{"log":"[2022-09-22 13:31:16,961] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:31:16.961493399Z"}
{"log":"[2022-09-22 13:31:26,964] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:31:26.964610719Z"}
{"log":"[2022-09-22 13:31:36,970] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:31:36.971114597Z"}
{"log":"[2022-09-22 13:31:46,971] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:31:46.971256831Z"}
{"log":"[2022-09-22 13:31:56,971] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:31:56.971409044Z"}
{"log":"[2022-09-22 13:32:06,971] INFO WorkerSourceTask{id=kafka-connect-safsrc-01-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask)\n","stream":"stdout","time":"2022-09-22T13:32:06.971536831Z"}
{"log":"[2022-09-22 13:32:14,000] DEBUG Fetching results for SCN [527420505725, 527420508551] (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:32:14.001132291Z"}
{"log":"[2022-09-22 13:32:14,642] DEBUG Counters{rows=610, stuckCount=0, dmlCount=0, ddlCount=0, insertCount=0, updateCount=0, deleteCount=0, commitCount=305, rollbackCount=0, tableMetadataCount=0}. (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:32:14.642248481Z"}
{"log":"[2022-09-22 13:32:14,642] DEBUG Processed in 358 ms. Lag: 3634. Offset SCN: 527420505290, Offset Commit SCN: CommitScn [redoThreadCommitScns={1=RedoThreadCommitScn{thread=1, commitScn=527420505189, rsId=' 0x00a664.0001e077.00f0 ', ssn=0}}], Active Transactions: 1, Sleep: 60000 (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:32:14.64227605Z"}

      i guess the line that stands out is:

      {"log":"[2022-09-22 13:31:16,779] DEBUG Transaction 3e000b00b71c4000 has already been processed. Offset Commit SCN CommitScn [redoThreadCommitScns={1=RedoThreadCommitScn{thread=1, commitScn=527420505068, rsId=' 0x00a664.0001dfc5.01d4 ', ssn=0}}], Transaction Commit SCN 527420505068, Last Seen Commit SCN 527420505068. (io.debezium.connector.oracle.logminer.processor.AbstractLogMinerEventProcessor)\n","stream":"stdout","time":"2022-09-22T13:31:16.779324686Z"}

       

      i am not using RAC but i wonder if https://issues.redhat.com/browse/DBZ-5439 would fix this?

       cc ccranfor@redhat.com

      Attachments

        Issue Links

          is incorporated by

          Bug - A problem that impairs or prevents the functions of the product. DBZ-6942 Connector frequently misses commit operations

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed
          is related to

          Bug - A problem that impairs or prevents the functions of the product. DBZ-5750 Missing oracle cdc records

          • Major - To be worked after higher priority work items are addressed. When the severity is high and the effort to change it is low to moderate, this term is chosen. Issues in this category likely have an existing workaround but implementation or execution may be non-trivial.
          • Closed
          links to

          Web Link RHEA-2024:129636 Red Hat build of Debezium 2.5.4 release

          Activity

            People

              ccranfor@redhat.com Chris Cranford
              tooptoop toop toop (Inactive)
              Votes:
              1 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: