IndexOutOfBoundsException

[朱义栓]

Hello, I hope I didn't disturb your rest. I have a question that I need help

IndexOutOfBoundsException : index 39 out of bounds for length

[Chris Cranford]

Hi,

Can you please share the complete exception so we know where this is being thrown.

Thanks,
Chris

On 2/23/24 11:02, 朱义栓 wrote:

Hello, I hope I didn't disturb your rest. I have a question that I need help

IndexOutOfBoundsException : index 39 out of bounds for length

--
You received this message because you are subscribed to the Google Groups "debezium" group.
To unsubscribe from this group and stop receiving emails from it, send an email to debezium+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/debezium/CAKaK%2BM-XM%2BCthBsU%2B-PadpXcYR%2BO-bZ3t9BBaovrmi%2BE%3DRa22g%40mail.gmail.com.

[朱义栓]

[2024-02-23 20:25:18,382] ERROR [pg-smsp-prod-source-V1|task-0] Producer failure (io.debezium.pipeline.ErrorHandler:35)
java.lang.IndexOutOfBoundsException: Index 39 out of bounds for length 39
        at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64)
        at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
        at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:248)
        at java.base/java.util.Objects.checkIndex(Objects.java:372)
        at java.base/java.util.ArrayList.get(ArrayList.java:458)
        at java.base/java.util.Collections$UnmodifiableList.get(Collections.java:1308)
        at java.base/java.util.Collections$UnmodifiableList.get(Collections.java:1308)
        at io.debezium.connector.postgresql.connection.pgoutput.PgOutputMessageDecoder.resolveColumnsFromStreamTupleData(PgOutputMessageDecoder.java:715)
        at io.debezium.connector.postgresql.connection.pgoutput.PgOutputMessageDecoder.decodeInsert(PgOutputMessageDecoder.java:417)
        at io.debezium.connector.postgresql.connection.pgoutput.PgOutputMessageDecoder.processNotEmptyMessage(PgOutputMessageDecoder.java:191)
        at io.debezium.connector.postgresql.connection.AbstractMessageDecoder.processMessage(AbstractMessageDecoder.java:33)
        at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.deserializeMessages(PostgresReplicationConnection.java:510)
        at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.readPending(PostgresReplicationConnection.java:502)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.processMessages(PostgresStreamingChangeEventSource.java:215)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.execute(PostgresStreamingChangeEventSource.java:177)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.execute(PostgresStreamingChangeEventSource.java:41)
        at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174)
        at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141)
        at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)





[2024-02-23 20:25:18,635] ERROR [pg-smsp-prod-source-V1|task-0] WorkerSourceTask{id=pg-smsp-prod-source-V1-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:195)
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:50)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.execute(PostgresStreamingChangeEventSource.java:180)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.execute(PostgresStreamingChangeEventSource.java:41)
        at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174)
        at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141)
        at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.IndexOutOfBoundsException: Index 39 out of bounds for length 39
        at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64)
        at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
        at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:248)
        at java.base/java.util.Objects.checkIndex(Objects.java:372)
        at java.base/java.util.ArrayList.get(ArrayList.java:458)
        at java.base/java.util.Collections$UnmodifiableList.get(Collections.java:1308)
        at java.base/java.util.Collections$UnmodifiableList.get(Collections.java:1308)
        at io.debezium.connector.postgresql.connection.pgoutput.PgOutputMessageDecoder.resolveColumnsFromStreamTupleData(PgOutputMessageDecoder.java:715)
        at io.debezium.connector.postgresql.connection.pgoutput.PgOutputMessageDecoder.decodeInsert(PgOutputMessageDecoder.java:417)
        at io.debezium.connector.postgresql.connection.pgoutput.PgOutputMessageDecoder.processNotEmptyMessage(PgOutputMessageDecoder.java:191)
        at io.debezium.connector.postgresql.connection.AbstractMessageDecoder.processMessage(AbstractMessageDecoder.java:33)
        at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.deserializeMessages(PostgresReplicationConnection.java:510)
        at io.debezium.connector.postgresql.connection.PostgresReplicationConnection$1.readPending(PostgresReplicationConnection.java:502)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.processMessages(PostgresStreamingChangeEventSource.java:215)
        at io.debezium.connector.postgresql.PostgresStreamingChangeEventSource.execute(PostgresStreamingChangeEventSource.java:177)

Chris Cranford <cran...@gmail.com>于2024年2月24日 周六00:35写道：

To view this discussion on the web visit https://groups.google.com/d/msgid/debezium/54a7ad85-1acf-4274-bbb1-5222bc3f47c4%40gmail.com.

[Chris Cranford]

Hi,

This seems to indicate that PostgreSQL sent a buffer with more columns than the relational model.  As PostgreSQL's pgoutput specification requires that it send an `R` (Relational) message before any type of DML event, so we should have gotten the complete column data before processing the insert. 

If you restart the connector and it still fails with this error, could you please enable TRACE logging, restart the connector until it fails, and then please attach the trace logs so that we can take a look at what could be doing on.  This is definitely not expected behavior with how the PgOutput protocol is designed.

Thanks,
Chris

[朱义栓]

hi , i add kafka connector config , "producer.override.metrics.recording.level":"TRACE" , but still only a small amount of logs are generated.

Error still reported after reboot :

[2024-03-07 20:04:28,575] ERROR [pg-smsp-prod-source-V1|task-0] Producer failure (io.debezium.pipeline.ErrorHandler:35)

[2024-03-07 20:04:28,579] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:04:28,582] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:04:28,583] INFO [pg-smsp-prod-source-V1|task-0] Finished streaming (io.debezium.pipeline.ChangeEventSourceCoordinator:175)
[2024-03-07 20:04:28,583] INFO [pg-smsp-prod-source-V1|task-0] Connected metrics set to 'false' (io.debezium.pipeline.ChangeEventSourceCoordinator:236)
[2024-03-07 20:04:28,803] INFO [pg-smsp-prod-source-V1|task-0] WorkerSourceTask{id=pg-smsp-prod-source-V1-0} Either no records were produced by the task since the last offset commit, or every record has been filtered out by a transformation or dropped due to transformation or conversion errors. (org.apache.kafka.connect.runtime.WorkerSourceTask:484)
[2024-03-07 20:04:28,807] ERROR [pg-smsp-prod-source-V1|task-0] WorkerSourceTask{id=pg-smsp-prod-source-V1-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:195)

        ... 9 more
[2024-03-07 20:04:28,808] INFO [pg-smsp-prod-source-V1|task-0] Stopping down connector (io.debezium.connector.common.BaseSourceTask:238)
[2024-03-07 20:04:28,811] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:04:28,812] INFO [pg-smsp-prod-source-V1|task-0] [Producer clientId=connector-producer-pg-smsp-prod-source-V1-0] Closing the Kafka producer with timeoutMillis = 30000 ms. (org.apache.kafka.clients.producer.KafkaProducer:1228)
[2024-03-07 20:04:28,817] INFO [pg-smsp-prod-source-V1|task-0] Metrics scheduler closed (org.apache.kafka.common.metrics.Metrics:659)
[2024-03-07 20:04:28,817] INFO [pg-smsp-prod-source-V1|task-0] Closing reporter org.apache.kafka.common.metrics.JmxReporter (org.apache.kafka.common.metrics.Metrics:663)
[2024-03-07 20:04:28,817] INFO [pg-smsp-prod-source-V1|task-0] Metrics reporters closed (org.apache.kafka.common.metrics.Metrics:669)
[2024-03-07 20:04:28,817] INFO [pg-smsp-prod-source-V1|task-0] App info kafka.producer for connector-producer-pg-smsp-prod-source-V1-0 unregistered (org.apache.kafka.common.utils.AppInfoParser:83)

# restart

[2024-03-07 20:40:09,276] INFO [pg-smsp-prod-source-V1|task-0] Starting streaming (io.debezium.pipeline.ChangeEventSourceCoordinator:173)
[2024-03-07 20:40:09,276] INFO [pg-smsp-prod-source-V1|task-0] Retrieved latest position from stored offset 'LSN{107D5/9CEF71D8}' (io.debezium.connector.postgresql.PostgresStreamingChangeEventSource:135)
[2024-03-07 20:40:09,276] INFO [pg-smsp-prod-source-V1|task-0] Looking for WAL restart position for last commit LSN 'LSN{107D5/9CEF71D8}' and last change LSN 'LSN{107D5/9CEF71D8}' (io.debezium.connector.postgresql.connection.WalPositionLocator:42)
[2024-03-07 20:40:09,276] INFO [pg-smsp-prod-source-V1|task-0] Initializing PgOutput logical decoder publication (io.debezium.connector.postgresql.connection.PostgresReplicationConnection:147)
[2024-03-07 20:40:09,713] INFO [pg-smsp-prod-source-V1|task-0] Obtained valid replication slot ReplicationSlot [active=false, latestFlushedLsn=LSN{107D5/9C7B64A8}, catalogXmin=2112396434] (io.debezium.connector.postgresql.connection.PostgresConnection:262)
[2024-03-07 20:40:09,717] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:40:09,799] INFO [pg-smsp-prod-source-V1|task-0] Requested thread factory for connector PostgresConnector, id = smsp named = keep-alive (io.debezium.util.Threads:270)
[2024-03-07 20:40:09,799] INFO [pg-smsp-prod-source-V1|task-0] Creating thread debezium-postgresconnector-smsp-keep-alive (io.debezium.util.Threads:287)
[2024-03-07 20:40:13,050] INFO [pg-smsp-prod-source-V1|task-0|offsets] WorkerSourceTask{id=pg-smsp-prod-source-V1-0} Either no records were produced by the task since the last offset commit, or every record has been filtered out by a transformation or dropped due to transformation or conversion errors. (org.apache.kafka.connect.runtime.WorkerSourceTask:484)

[2024-03-07 20:46:36,881] INFO [pg-smsp-prod-source-V1|task-0] Searching for WAL resume position (io.debezium.connector.postgresql.PostgresStreamingChangeEventSource:323)
[2024-03-07 20:46:36,881] INFO [pg-smsp-prod-source-V1|task-0] First LSN 'LSN{107D5/9CEF71D8}' received (io.debezium.connector.postgresql.connection.WalPositionLocator:62)
[2024-03-07 20:46:37,044] INFO [pg-smsp-prod-source-V1|task-0] LSN after last stored change LSN 'LSN{107D5/9CEF84F0}' received (io.debezium.connector.postgresql.connection.WalPositionLocator:73)
[2024-03-07 20:46:37,044] INFO [pg-smsp-prod-source-V1|task-0] WAL resume position 'LSN{107D5/9CEF84F0}' discovered (io.debezium.connector.postgresql.PostgresStreamingChangeEventSource:344)
[2024-03-07 20:46:37,085] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:46:37,087] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:46:37,248] INFO [pg-smsp-prod-source-V1|task-0] Initializing PgOutput logical decoder publication (io.debezium.connector.postgresql.connection.PostgresReplicationConnection:147)
[2024-03-07 20:46:37,377] INFO [pg-smsp-prod-source-V1|task-0] Requested thread factory for connector PostgresConnector, id = smsp named = keep-alive (io.debezium.util.Threads:270)
[2024-03-07 20:46:37,377] INFO [pg-smsp-prod-source-V1|task-0] Creating thread debezium-postgresconnector-smsp-keep-alive (io.debezium.util.Threads:287)
[2024-03-07 20:46:37,377] INFO [pg-smsp-prod-source-V1|task-0] Processing messages (io.debezium.connector.postgresql.PostgresStreamingChangeEventSource:210)
[2024-03-07 20:46:37,732] INFO [pg-smsp-prod-source-V1|task-0] Streaming requested from LSN LSN{107D5/9CEF71D8}, received LSN LSN{107D5/9CEF71D8} identified as already processed (io.debezium.connector.postgresql.connection.AbstractMessageDecoder:45)
[2024-03-07 20:46:37,733] INFO [pg-smsp-prod-source-V1|task-0] Streaming requested from LSN LSN{107D5/9CEF71D8}, received LSN LSN{0/0} identified as already processed (io.debezium.connector.postgresql.connection.AbstractMessageDecoder:45)
[2024-03-07 20:46:37,822] INFO [pg-smsp-prod-source-V1|task-0] Streaming requested from LSN LSN{107D5/9CEF71D8}, received LSN LSN{107D5/9CEF71D8} identified as already processed (io.debezium.connector.postgresql.connection.AbstractMessageDecoder:45)
[2024-03-07 20:46:37,822] INFO [pg-smsp-prod-source-V1|task-0] Message with LSN 'LSN{107D5/9CEF84F0}' arrived, switching off the filtering (io.debezium.connector.postgresql.connection.WalPositionLocator:136)
[2024-03-07 20:46:38,032] INFO [pg-smsp-prod-source-V1|task-0] 6 records sent during previous 00:12:55.0, last recorded offset: {transaction_id=null, lsn_proc=290089019288208, lsn_commit=290089019288208, lsn=290089019288208, txId=2112400153, ts_usec=1709813070159052} (io.debezium.connector.common.BaseSourceTask:182)
[2024-03-07 20:46:38,079] ERROR [pg-smsp-prod-source-V1|task-0] Producer failure (io.debezium.pipeline.ErrorHandler:35)

[2024-03-07 20:46:38,083] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:46:38,085] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:46:38,085] INFO [pg-smsp-prod-source-V1|task-0] Finished streaming (io.debezium.pipeline.ChangeEventSourceCoordinator:175)
[2024-03-07 20:46:38,085] INFO [pg-smsp-prod-source-V1|task-0] Connected metrics set to 'false' (io.debezium.pipeline.ChangeEventSourceCoordinator:236)
[2024-03-07 20:46:38,538] INFO [pg-smsp-prod-source-V1|task-0] WorkerSourceTask{id=pg-smsp-prod-source-V1-0} Either no records were produced by the task since the last offset commit, or every record has been filtered out by a transformation or dropped due to transformation or conversion errors. (org.apache.kafka.connect.runtime.WorkerSourceTask:484)
[2024-03-07 20:46:38,542] ERROR [pg-smsp-prod-source-V1|task-0] WorkerSourceTask{id=pg-smsp-prod-source-V1-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:195)

        ... 9 more
[2024-03-07 20:46:38,544] INFO [pg-smsp-prod-source-V1|task-0] Stopping down connector (io.debezium.connector.common.BaseSourceTask:238)
[2024-03-07 20:46:38,545] INFO [pg-smsp-prod-source-V1|task-0] Connection gracefully closed (io.debezium.jdbc.JdbcConnection:956)
[2024-03-07 20:46:38,546] INFO [pg-smsp-prod-source-V1|task-0] [Producer clientId=connector-producer-pg-smsp-prod-source-V1-0] Closing the Kafka producer with timeoutMillis = 30000 ms. (org.apache.kafka.clients.producer.KafkaProducer:1228)
[2024-03-07 20:46:38,550] INFO [pg-smsp-prod-source-V1|task-0] Metrics scheduler closed (org.apache.kafka.common.metrics.Metrics:659)
[2024-03-07 20:46:38,550] INFO [pg-smsp-prod-source-V1|task-0] Closing reporter org.apache.kafka.common.metrics.JmxReporter (org.apache.kafka.common.metrics.Metrics:663)
[2024-03-07 20:46:38,550] INFO [pg-smsp-prod-source-V1|task-0] Metrics reporters closed (org.apache.kafka.common.metrics.Metrics:669)
[2024-03-07 20:46:38,551] INFO [pg-smsp-prod-source-V1|task-0] App info kafka.producer for connector-producer-pg-smsp-prod-source-V1-0 unregistered (org.apache.kafka.common.utils.AppInfoParser:83)

Chris Cranford <cran...@gmail.com> 于2024年2月24日周六 10:56写道：

To view this discussion on the web visit https://groups.google.com/d/msgid/debezium/e841f869-ceab-4de4-a27b-efcd8ef3adc3n%40googlegroups.com.

[Chris Cranford]

Hi,

Unfortunately that is not going to set the log level to TRACE for what we asked. 
You can find information on how to set the log levels in Kafka Connect in the documentation [1].

Let us know if you have any questions.
Chris

[1]: https://debezium.io/documentation/reference/stable/operations/logging.html

To view this discussion on the web visit https://groups.google.com/d/msgid/debezium/CAKaK%2BM_mzkBPbPx4D%3DcXRDO1aADvZw-LJ3jxmyFw9Tdy3R%3DMzw%40mail.gmail.com.