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

Oracle connector - NPE at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkTableColumnNameLengths(LogMinerStreamingChangeEventSource.java:579)

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Duplicate Issue
    • 1.8.0.Alpha2
    • None
    • oracle-connector
    • None

    Description

      this is first time doing snapshot for these tables (i have auto topic create enabled)

       

      XXMEM_LL_HEADERS only 767 rows ended up in topic when should be 2014 rows.

      FND_LOCATIONS topic never got created!

       

      [2021-11-17 14:52:54,471] INFO Exporting data from table 'MYORAS.MYSCHM.XXMEM_LL_HEADERS' (4 of 5 tables) (io.debezium.relational.RelationalSnapshotChangeEventSource:340)[2021-11-17 14:52:54,471] INFO Exporting data from table 'MYORAS.MYSCHM.XXMEM_LL_HEADERS' (4 of 5 tables) (io.debezium.relational.RelationalSnapshotChangeEventSource:340)[2021-11-17 14:52:54,472] INFO   For table 'MYORAS.MYSCHM.XXMEM_LL_HEADERS' using select statement: 'SELECT "LLH_ID", "ORG_ID", "LEASELINE_REF", "EFFECTIVE_FROM_DATE", "EFFECTIVE_TO_DATE", "MAXIMUM_AMOUNT", "COMMITTED", "BASE_TERM", "STATUS", "CUSTOMER_ID", "CREDIT_LIMIT_ID", "TEMPLATE_ID", "LL_RE_APPROVAL", "LAST_USED_DRAWDOWN_SEQ", "WF_ITEMKEY", "DD_APPROVAL_ITEMKEY", "CREATED_BY", "CREATION_DATE", "LAST_UPDATED_BY", "LAST_UPDATE_DATE" FROM "MYSCHM"."XXMEM_LL_HEADERS" AS OF SCN 521126125711' (io.debezium.relational.RelationalSnapshotChangeEventSource:348)[2021-11-17 14:52:54,546] INFO   Finished exporting 2014 records for table 'MYORAS.MYSCHM.XXMEM_LL_HEADERS'; total duration '00:00:00.075' (io.debezium.relational.RelationalSnapshotChangeEventSource:393)[2021-11-17 14:52:54,547] INFO Exporting data from table 'MYORAS.MYSCHM2.FND_LOCATIONS' (5 of 5 tables) (io.debezium.relational.RelationalSnapshotChangeEventSource:340)[2021-11-17 14:52:54,547] INFO   For table 'MYORAS.MYSCHM2.FND_LOCATIONS' using select statement: 'SELECT "TERRITORY_CODE", "LAST_UPDATE_DATE", "LAST_UPDATED_BY", "CREATION_DATE", "CREATED_BY", "LAST_UPDATE_LOGIN", "ISO_NUMERIC_CODE", "ALTERNATE_TERRITORY_CODE", "ADDRESS_STYLE", "ADDRESS_VALIDATION", "BANK_INFO_STYLE", "BANK_INFO_VALIDATION", "NLS_TERRITORY", "EU_CODE", "OBSOLETE_FLAG", "ISO_TERRITORY_CODE" FROM "MYSCHM2"."FND_LOCATIONS" AS OF SCN 521126125711' (io.debezium.relational.RelationalSnapshotChangeEventSource:348)[2021-11-17 14:52:54,562] INFO   Finished exporting 252 records for table 'MYORAS.MYSCHM2.FND_LOCATIONS'; total duration '00:00:00.015' (io.debezium.relational.RelationalSnapshotChangeEventSource:393)[2021-11-17 14:52:54,567] INFO Snapshot - Final stage (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource:83)[2021-11-17 14:52:54,583] INFO Snapshot ended with SnapshotResult [status=COMPLETED, offset=OracleOffsetContext [scn=521126125711]] (io.debezium.pipeline.ChangeEventSourceCoordinator:119)[2021-11-17 14:52:54,587] INFO Connected metrics set to 'true' (io.debezium.pipeline.metrics.StreamingChangeEventSourceMetrics:70)[2021-11-17 14:52:54,587] INFO Starting streaming (io.debezium.pipeline.ChangeEventSourceCoordinator:163)[2021-11-17 14:52:54,590] INFO The task will send records to topic 'my-topicoracle-prj.MYSCHM.XXMEM_LL_HEADERS' for the first time. Checking whether topic exists (org.apache.kafka.connect.runtime.WorkerSourceTask:424)[2021-11-17 14:52:54,595] INFO Creating topic 'my-topicoracle-prj.MYSCHM.XXMEM_LL_HEADERS' (org.apache.kafka.connect.runtime.WorkerSourceTask:433)[2021-11-17 14:52:54,797] INFO Created topic (name=my-topicoracle-prj.MYSCHM.XXMEM_LL_HEADERS, numPartitions=12, replicationFactor=3, replicasAssignments=null, configs={}) on brokers at redact1:9098,redact2:9098,redact3:9098 (org.apache.kafka.connect.util.TopicAdmin:389)[2021-11-17 14:52:54,797] INFO Created topic '(name=my-topicoracle-prj.MYSCHM.XXMEM_LL_HEADERS, numPartitions=12, replicationFactor=3, replicasAssignments=null, configs={})' using creation group TopicCreationGroup{name='default', inclusionPattern=.*, exclusionPattern=, numPartitions=12, replicationFactor=3, otherConfigs={}} (org.apache.kafka.connect.runtime.WorkerSourceTask:441)[2021-11-17 14:52:54,956] ERROR Mining session stopped due to the {} (io.debezium.connector.oracle.logminer.LogMinerHelper:86)java.lang.NullPointerException at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkTableColumnNameLengths(LogMinerStreamingChangeEventSource.java:579) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkDatabaseAndTableState(LogMinerStreamingChangeEventSource.java:555) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:119) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:58) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:166) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:127) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)[2021-11-17 14:52:54,959] ERROR Producer failure (io.debezium.pipeline.ErrorHandler:31)java.lang.NullPointerException at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkTableColumnNameLengths(LogMinerStreamingChangeEventSource.java:579) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkDatabaseAndTableState(LogMinerStreamingChangeEventSource.java:555) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:119) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:58) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:166) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:127) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)[2021-11-17 14:52:54,959] INFO startScn=521126125711, endScn=null (io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource:183)[2021-11-17 14:52:54,959] INFO Streaming metrics dump: OracleStreamingChangeEventSourceMetrics{currentScn=null, oldestScn=null, committedScn=null, offsetScn=null, logMinerQueryCount=0, totalProcessedRows=0, totalCapturedDmlCount=0, totalDurationOfFetchingQuery=PT0S, lastCapturedDmlCount=0, lastDurationOfFetchingQuery=PT0S, maxCapturedDmlCount=0, maxDurationOfFetchingQuery=PT0S, totalBatchProcessingDuration=PT0S, lastBatchProcessingDuration=PT0S, maxBatchProcessingThroughput=0, currentLogFileName=[], minLogFilesMined=0, maxLogFilesMined=0, redoLogStatus=[], switchCounter=0, batchSize=20000, millisecondToSleepBetweenMiningQuery=1000, hoursToKeepTransaction=0, networkConnectionProblemsCounter0, batchSizeDefault=20000, batchSizeMin=1000, batchSizeMax=100000, sleepTimeDefault=1000, sleepTimeMin=0, sleepTimeMax=3000, sleepTimeIncrement=200, totalParseTime=PT0S, totalStartLogMiningSessionDuration=PT0S, lastStartLogMiningSessionDuration=PT0S, maxStartLogMiningSessionDuration=PT0S, totalProcessTime=PT0S, minBatchProcessTime=PT0S, maxBatchProcessTime=PT0S, totalResultSetNextTime=PT0S, lagFromTheSource=DurationPT0S, maxLagFromTheSourceDuration=PT0S, minLagFromTheSourceDuration=PT0S, lastCommitDuration=PT0S, maxCommitDuration=PT0S, activeTransactions=0, rolledBackTransactions=0, committedTransactions=0, abandonedTransactionIds=[], rolledbackTransactionIds=[], registeredDmlCount=0, committedDmlCount=0, errorCount=1, warningCount=0, scnFreezeCount=0, unparsableDdlCount=0, miningSessionUserGlobalAreaMemory=0, miningSessionUserGlobalAreaMaxMemory=0, miningSessionProcessGlobalAreaMemory=0, miningSessionProcessGlobalAreaMaxMemory=0} (io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource:184)[2021-11-17 14:52:54,959] INFO Offsets: OracleOffsetContext [scn=521126125711] (io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource:185)[2021-11-17 14:52:54,959] INFO Finished streaming (io.debezium.pipeline.ChangeEventSourceCoordinator:167)[2021-11-17 14:52:54,959] INFO Connected metrics set to 'false' (io.debezium.pipeline.metrics.StreamingChangeEventSourceMetrics:70)[2021-11-17 14:52:55,349] INFO WorkerSourceTask{id=oracle-prj-source12-0} flushing 0 outstanding messages for offset commit (org.apache.kafka.connect.runtime.WorkerSourceTask:510)[2021-11-17 14:52:55,350] ERROR WorkerSourceTask{id=oracle-prj-source12-0} Task threw an uncaught and unrecoverable exception. Task is being killed and will not recover until manually restarted (org.apache.kafka.connect.runtime.WorkerTask:190)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:42) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:180) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:58) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:166) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:127) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)Caused by: java.lang.NullPointerException at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkTableColumnNameLengths(LogMinerStreamingChangeEventSource.java:579) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.checkDatabaseAndTableState(LogMinerStreamingChangeEventSource.java:555) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:119) ... 8 more[2021-11-17 14:52:55,350] INFO Stopping down connector (io.debezium.connector.common.BaseSourceTask:241)[2021-11-17 14:52:55,362] INFO Connection gracefully closed (io.debezium.jdbc.JdbcConnection:965)
      

      Attachments

        Issue Links

          Activity

            People

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

              Dates

                Created:
                Updated:
                Resolved: