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

Unexpected exception while streaming changes from row with unchanged toast

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Done
    • Affects Version/s: 0.9.1.Final
    • Fix Version/s: 0.9.2.Final
    • Component/s: postgresql-connector
    • Labels:
      None
    • Environment:

      Running in docker
      debezium/connect:0.9.1.Final
      debezium/postgres:0.9.1.Final (modified to use wal2json commit 9e962bad61ef2bfa53747470bac4d465e71df880 to match AWS RDS)
      debezium/kafka:0.9.1.Final

    • Steps to Reproduce:
      Hide

      I've reproduced this a few different ways, here is one:

      CREATE DATABASE test;
\c test;
CREATE TABLE sample (sample_id int primary key,data text);
INSERT INTO sample VALUES (1, 'foo');
INSERT INTO sample VALUES(2, <<something very large>>); # in my case, it had over 82000 characters

      With debezium configured to stream changes from this database, updating the sample_id on either row is fine.

      But then

      ALTER TABLE ONLY sample REPLICA IDENTITY FULL;

      Now updating the sample_id on the row with the large value causes the above error in debezium.

      Show
      I've reproduced this a few different ways, here is one: CREATE DATABASE test; \ c test; CREATE TABLE sample (sample_id int primary key , data text ); INSERT INTO sample VALUES (1, 'foo' ); INSERT INTO sample VALUES (2, <<something very large >>); # in my case , it had over 82000 characters With debezium configured to stream changes from this database, updating the sample_id on either row is fine. But then ALTER TABLE ONLY sample REPLICA IDENTITY FULL ; Now updating the sample_id on the row with the large value causes the above error in debezium.

      Description

      I am getting the following exception in debezium when streaming changes from a table that has a text column with a row with a fairly large value. Here is a snapshot of the logs. The full logs (as output by docker-compose logs are attached, as is my connect/register payload.

      Some notes:
      This behavior is unaffected by doing any of the following:

      • Adding this text column to the column.blacklist setting for debezium
      • Setting schema.refresh.mode to columns_diff_exclude_unchanged_toast

      This is actually happening for me in my Postgres 10.6 on RDS, but I have been able to reproduce it locally.

      2019-02-15 14:50:29,114 ERROR  Postgres|dbserver1|records-stream-producer  unexpected exception while streaming logical changes   [io.debezium.connector.postgresql.RecordsStreamProducer]
java.lang.NullPointerException
	at io.debezium.connector.postgresql.RecordsStreamProducer.columnValues(RecordsStreamProducer.java:455)
	at io.debezium.connector.postgresql.RecordsStreamProducer.process(RecordsStreamProducer.java:263)
	at io.debezium.connector.postgresql.RecordsStreamProducer.lambda$streamChanges$1(RecordsStreamProducer.java:133)
	at io.debezium.connector.postgresql.connection.wal2json.NonStreamingWal2JsonMessageDecoder.processMessage(NonStreamingWal2JsonMessageDecoder.java:62)
	at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.deserializeMessages(PostgresReplicationConnection.java:265)
	at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.read(PostgresReplicationConnection.java:250)
	at io.debezium.connector.postgresql.RecordsStreamProducer.streamChanges(RecordsStreamProducer.java:133)
	at io.debezium.connector.postgresql.RecordsStreamProducer.lambda$start$0(RecordsStreamProducer.java:119)
	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)
2019-02-15 14:50:29,405 INFO   ||  WorkerSourceTask{id=connector-0} Committing offsets   [org.apache.kafka.connect.runtime.WorkerSourceTask]
2019-02-15 14:50:29,405 INFO   ||  WorkerSourceTask{id=connector-0} flushing 0 outstanding messages for offset commit   [org.apache.kafka.connect.runtime.WorkerSourceTask]
2019-02-15 14:50:29,406 ERROR  ||  WorkerSourceTask{id=connector-0} Task threw an uncaught and unrecoverable exception   [org.apache.kafka.connect.runtime.WorkerTask]
org.apache.kafka.connect.errors.ConnectException: An exception ocurred in the change event producer. This connector will be stopped.
	at io.debezium.connector.base.ChangeEventQueue.throwProducerFailureIfPresent(ChangeEventQueue.java:170)
	at io.debezium.connector.base.ChangeEventQueue.poll(ChangeEventQueue.java:151)
	at io.debezium.connector.postgresql.PostgresConnectorTask.poll(PostgresConnectorTask.java:156)
	at org.apache.kafka.connect.runtime.WorkerSourceTask.poll(WorkerSourceTask.java:244)
	at org.apache.kafka.connect.runtime.WorkerSourceTask.execute(WorkerSourceTask.java:220)
	at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:175)
	at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:219)
	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.postgresql.RecordsStreamProducer.columnValues(RecordsStreamProducer.java:455)
	at io.debezium.connector.postgresql.RecordsStreamProducer.process(RecordsStreamProducer.java:263)
	at io.debezium.connector.postgresql.RecordsStreamProducer.lambda$streamChanges$1(RecordsStreamProducer.java:133)
	at io.debezium.connector.postgresql.connection.wal2json.NonStreamingWal2JsonMessageDecoder.processMessage(NonStreamingWal2JsonMessageDecoder.java:62)
	at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.deserializeMessages(PostgresReplicationConnection.java:265)
	at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.read(PostgresReplicationConnection.java:250)
	at io.debezium.connector.postgresql.RecordsStreamProducer.streamChanges(RecordsStreamProducer.java:133)
	at io.debezium.connector.postgresql.RecordsStreamProducer.lambda$start$0(RecordsStreamProducer.java:119)
	... 5 more

        Gliffy Diagrams

          Attachments

          1. dbz_logs
            163 kB
          2. register.json
            0.5 kB

            Activity

              People

              • Assignee:
                jpechanec Jiri Pechanec
                Reporter:
                rkilgore84 Ross Kilgore
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: