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

NPE during sending to HTTP sink

XMLWordPrintable

    • Moderate

      What Debezium connector do you use and what version?

       debezium-server-dist 3.3.1.Final on JVM (powered by Quarkus 3.15.4)

      What is the connector configuration?

      The relevant part is roughly this (in a Docker Compose configuration)

      # HTTP sink configuration
debezium.sink.type=http
debezium.sink.http.url=http://webhook:8080/webhook

      What is the captured database version and mode of deployment?

      Not so relevant for this ticket, but an Oracle 19.3.0 enterprise container running in Docker Compose.

      What behavior do you expect?

      Not throwing a NPE.

      What behavior do you see?

      debezium-1  | 2025-11-21 10:50:00,349 INFO  [io.deb.con.com.BaseSourceTask] (pool-9-thread-1) 7 records sent during previous 19:35:57.203, last recorded offset of {server=thaler} partition is {commit_scn=1904709:1:01001c00ee010000, txSeq=1, txId=0300130089010000, snapshot_scn=1665849, scn=1904675}
debezium-1  | 2025-11-21 10:50:00,508 ERROR [io.deb.emb.asy.AsyncEmbeddedEngine] (pool-8-thread-1) Engine has failed with : java.util.concurrent.ExecutionException: java.lang.NullPointerException: Cannot invoke "String.contains(java.lang.CharSequence)" because the return value of "java.io.IOException.getMessage()" is null
debezium-1  |     at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
debezium-1  |     at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
debezium-1  |     at io.debezium.embedded.async.AsyncEmbeddedEngine.runTasksPolling(AsyncEmbeddedEngine.java:536)
debezium-1  |     at io.debezium.embedded.async.AsyncEmbeddedEngine.run(AsyncEmbeddedEngine.java:222)
debezium-1  |     at io.debezium.server.DebeziumServer.lambda$start$1(DebeziumServer.java:182)
debezium-1  |     at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
debezium-1  |     at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
debezium-1  |     at java.base/java.lang.Thread.run(Thread.java:1583)
debezium-1  | Caused by: java.lang.NullPointerException: Cannot invoke "String.contains(java.lang.CharSequence)" because the return value of "java.io.IOException.getMessage()" is null
debezium-1  |     at io.debezium.server.http.HttpChangeConsumer.recordSent(HttpChangeConsumer.java:213)
debezium-1  |     at io.debezium.server.http.HttpChangeConsumer.handleBatch(HttpChangeConsumer.java:158)
debezium-1  |     at io.debezium.embedded.async.ParallelSmtAndConvertBatchProcessor.processRecords(ParallelSmtAndConvertBatchProcessor.java:56)
debezium-1  |     at io.debezium.embedded.async.AsyncEmbeddedEngine$PollRecords.doCall(AsyncEmbeddedEngine.java:1249)
debezium-1  |     at io.debezium.embedded.async.AsyncEmbeddedEngine$PollRecords.doCall(AsyncEmbeddedEngine.java:1229)
debezium-1  |     at io.debezium.embedded.async.RetryingCallable.call(RetryingCallable.java:47)
debezium-1  |     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
debezium-1  |     at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
debezium-1  |     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
debezium-1  |     ... 3 more
debezium-1  |
debezium-1  | 2025-11-21 10:50:00,515 INFO  [io.deb.emb.asy.AsyncEmbeddedEngine] (pool-8-thread-1) Engine state has changed from 'POLLING_TASKS' to 'STOPPING'
debezium-1  | 2025-11-21 10:50:00,517 INFO  [io.deb.con.com.BaseSourceTask] (pool-9-thread-1) Stopping down connector
debezium-1  | 2025-11-21 10:50:03,238 INFO  [io.deb.con.ora.log.AbstractLogMinerStreamingChangeEventSource] (debezium-oracleconnector-thaler-change-event-source-coordinator) Streaming metrics at shutdown: LogMinerStreamingChangeEventSourceMetrics{connectorConfig=io.debezium.connector.oracle.OracleConnectorConfig@682c94c0, startTime=2025-11-20T15:14:03.402951545Z, clock=SystemClock[Z], currentScn=1904724, offsetScn=1904712, commitScn=1904712, oldestScn=null, oldestScnTime=null, currentLogFileNames=[/opt/oracle/oradata/ORCLCDB/redo03.log], redoLogStatuses=[/opt/oracle/oradata/ORCLCDB/redo03.log | CURRENT, /opt/oracle/oradata/ORCLCDB/redo01.log | INACTIVE, /opt/oracle/oradata/ORCLCDB/redo02.log | INACTIVE], databaseZoneOffset=Z, batchSize=20000, logSwitchCount=0, logMinerQueryCount=4452, sleepTime=3000, minimumLogsMined=1, maximumLogsMined=2, maxBatchProcessingThroughput=6230, timeDifference=0, processedRowsCount=15105, activeTransactionCount=0, rolledBackTransactionCount=7, oversizedTransactionCount=0, changesCount=10, scnFreezeCount=0, batchProcessingDuration={min=PT0.030830667S,max=PT20M33.926174569S,total=PT35M57.35789588S}, fetchQueryDuration={min=PT0.017535958S,max=PT20M33.865246319S,total=PT31M11.744087756S}, commitDuration={min=PT0.000461542S,max=PT0.073401958S,total=PT0.215091561S}, lagFromSourceDuration={min=PT1.409649427S,max=PT3H1M57.805645087S,total=PT1426H15M24.879322788S}, miningSessionStartupDuration={min=PT0.001348333S,max=PT0.235087708S,total=PT12.755089018S}, parseTimeDuration={min=PT0.000034708S,max=PT0S,total=PT0.001066872S}, resultSetNextDuration={min=PT0.000000167S,max=PT0S,total=PT0.008314588S}, userGlobalAreaMemory={value=899976,max=2878160}, processGlobalAreaMemory={value=8576984,max=40099800}, abandonedTransactionIds=[], rolledBackTransactionIds=[0a00130013030000, 0a00160044030000, 0300180081010000, 0300140081010000, 0300200081010000, 06000d00db020000, 06001300db020000]}
debezium-1  | 2025-11-21 10:50:03,239 INFO  [io.deb.con.ora.log.AbstractLogMinerStreamingChangeEventSource] (debezium-oracleconnector-thaler-change-event-source-coordinator) Offsets as shutdown: OracleOffsetContext [scn=1904712, txId=0300130089010000, txSeq=1, commit_scn=["1904712:1:0300130089010000"], lcr_position=null]
debezium-1  | 2025-11-21 10:50:03,239 INFO  [io.deb.pip.ChangeEventSourceCoordinator] (debezium-oracleconnector-thaler-change-event-source-coordinator) Finished streaming
debezium-1  | 2025-11-21 10:50:03,240 INFO  [io.deb.pip.ChangeEventSourceCoordinator] (debezium-oracleconnector-thaler-change-event-source-coordinator) Connected metrics set to 'false'
debezium-1  | 2025-11-21 10:50:03,241 INFO  [io.deb.pip.sig.SignalProcessor] (pool-9-thread-1) SignalProcessor stopped
debezium-1  | 2025-11-21 10:50:03,242 INFO  [io.deb.ser.DefaultServiceRegistry] (pool-9-thread-1) Debezium ServiceRegistry stopped.
debezium-1  | 2025-11-21 10:50:03,244 INFO  [io.deb.uti.Threads] (pool-9-thread-1) Requested thread factory for component JdbcConnection, id = JdbcConnection named = jdbc-connection-close
debezium-1  | 2025-11-21 10:50:03,244 INFO  [io.deb.uti.Threads] (pool-9-thread-1) Creating thread debezium-jdbcconnection-JdbcConnection-jdbc-connection-close
debezium-1  | 2025-11-21 10:50:03,250 INFO  [io.deb.jdb.JdbcConnection] (debezium-jdbcconnection-JdbcConnection-jdbc-connection-close) Connection gracefully closed
debezium-1  | 2025-11-21 10:50:03,251 INFO  [io.deb.uti.Threads] (pool-9-thread-1) Requested thread factory for component JdbcConnection, id = JdbcConnection named = jdbc-connection-close
debezium-1  | 2025-11-21 10:50:03,251 INFO  [io.deb.uti.Threads] (pool-9-thread-1) Creating thread debezium-jdbcconnection-JdbcConnection-jdbc-connection-close
debezium-1  | 2025-11-21 10:50:03,259 INFO  [io.deb.jdb.JdbcConnection] (debezium-jdbcconnection-JdbcConnection-jdbc-connection-close) Connection gracefully closed
debezium-1  | 2025-11-21 10:50:03,270 INFO  [io.deb.emb.asy.AsyncEmbeddedEngine] (pool-8-thread-1) Stopped task #1 out of 1 tasks (it took 2753 ms to stop the task).
debezium-1  | 2025-11-21 10:50:03,281 INFO  [io.deb.sto.jdb.off.JdbcOffsetBackingStore] (pool-8-thread-1) Stopped JdbcOffsetBackingStore
debezium-1  | 2025-11-21 10:50:03,281 INFO  [io.deb.emb.asy.AsyncEmbeddedEngine] (pool-8-thread-1) Engine is stopped.
debezium-1  | 2025-11-21 10:50:03,281 INFO  [io.deb.emb.asy.AsyncEmbeddedEngine] (pool-8-thread-1) Engine state has changed from 'STOPPING' to 'STOPPED'
debezium-1  | 2025-11-21 10:50:03,282 ERROR [io.deb.ser.ConnectorLifecycle] (pool-8-thread-1) Connector completed: success = 'false', message = 'java.lang.NullPointerException: Cannot invoke "String.contains(java.lang.CharSequence)" because the return value of "java.io.IOException.getMessage()" is null', error = 'java.lang.NullPointerException: Cannot invoke "String.contains(java.lang.CharSequence)" because the return value of "java.io.IOException.getMessage()" is null': java.lang.NullPointerException: Cannot invoke "String.contains(java.lang.CharSequence)" because the return value of "java.io.IOException.getMessage()" is null
debezium-1  |     at io.debezium.server.http.HttpChangeConsumer.recordSent(HttpChangeConsumer.java:213)
debezium-1  |     at io.debezium.server.http.HttpChangeConsumer.handleBatch(HttpChangeConsumer.java:158)
debezium-1  |     at io.debezium.embedded.async.ParallelSmtAndConvertBatchProcessor.processRecords(ParallelSmtAndConvertBatchProcessor.java:56)
debezium-1  |     at io.debezium.embedded.async.AsyncEmbeddedEngine$PollRecords.doCall(AsyncEmbeddedEngine.java:1249)
debezium-1  |     at io.debezium.embedded.async.AsyncEmbeddedEngine$PollRecords.doCall(AsyncEmbeddedEngine.java:1229)
debezium-1  |     at io.debezium.embedded.async.RetryingCallable.call(RetryingCallable.java:47)
debezium-1  |     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
debezium-1  |     at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
debezium-1  |     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
debezium-1  |     at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
debezium-1  |     at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
debezium-1  |     at java.base/java.lang.Thread.run(Thread.java:1583)
debezium-1  |
debezium-1  | 2025-11-21 10:50:03,298 INFO  [io.deb.ser.DebeziumServer] (main) Received request to stop the engine
debezium-1  | 2025-11-21 10:50:03,299 INFO  [io.deb.ser.DebeziumServer] (main) Cannot shut down engine now:
debezium-1  | 2025-11-21 10:50:03,319 INFO  [io.quarkus] (main) debezium-server-dist stopped in 0.034s
debezium-1 exited with code 1 (restarting)

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

      Yes.

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

      I have the above, but the issue is clear. When an IOException is thrown without a message an NPE is thrown and the application terminates.

      How to reproduce the issue using our tutorial deployment?

      N/A

       

              Unassigned Unassigned
              aukevanleeuwen Auke van Leeuwen
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: