Receiving NumberFormatException

[SaurabhNair239]

Hello,

I was trying to implement CDC on the AS400 system while doing so I am constantly receiving an error "class":"java.lang.NumberFormatException","message":"High-order nibble of the byte at array offset 5036 is not valid. Byte value: 20" . I have tried to go through the journal files but couldn't find anything suspicious there. Thus, can anyone of you please help me out to know how I can get though this or how to debug it.

Thanks in advance.

[msillence]

It sounds like the type on the table is deteched as some sort of number and when we try and decode it, the value is not valid for that decoder.
It is possible I'm mapping the column type incorrectly or you have non numberic data in a numeric column.

I'd need to know the column type on the table to further diagnose. Hopefully it will log the table name, if not you could turn on debug logging adding a line to log4j2.xml like : <Logger name="io.debezium.connector.db2as400.As400StreamingChangeEventSource" level="debug" additivity="true"/> in the loggers section

Then we need to work out what column it is. If it's not obvious I might need to add some code to aid diagnostics. What's the full stack trace look like?

[SaurabhNair239]

The column type is ZONED. We would like to know how actually the data look like inside the connector.

The full stack trace is as below:

java.lang.NumberFormatException: High-order nibble of the byte at array offset 860 is not valid. Byte value: 20
at com.ibm.as400.access.AS400ZonedDecimal.throwNumberFormatException(AS400ZonedDecimal.java:527) ~[jt400-jdk9-11.1.jar:JTOpen 11.1]
at com.ibm.as400.access.AS400ZonedDecimal.toObject(AS400ZonedDecimal.java:489) ~[jt400-jdk9-11.1.jar:JTOpen 11.1]
at com.ibm.as400.access.AS400Structure.toObject(AS400Structure.java:375) ~[jt400-jdk9-11.1.jar:JTOpen 11.1]
at com.fnz.db2.journal.retrieve.JdbcFileDecoder.decodeEntry(JdbcFileDecoder.java:100) ~[journal-parsing-1.9.20.jar:?]
at com.fnz.db2.journal.retrieve.JdbcFileDecoder.lambda$decodeFile$0(JdbcFileDecoder.java:88) ~[journal-parsing-1.9.20.jar:?]
at java.util.Optional.map(Optional.java:260) ~[?:?]
at com.fnz.db2.journal.retrieve.JdbcFileDecoder.decodeFile(JdbcFileDecoder.java:83) ~[journal-parsing-1.9.20.jar:?]
at com.fnz.db2.journal.retrieve.JournalFileEntryDecoder.decode(JournalFileEntryDecoder.java:19) ~[journal-parsing-1.9.20.jar:?]
at com.fnz.db2.journal.retrieve.JournalFileEntryDecoder.decode(JournalFileEntryDecoder.java:9) ~[journal-parsing-1.9.20.jar:?]
at com.fnz.db2.journal.retrieve.RetrieveJournal.decode(RetrieveJournal.java:290) ~[journal-parsing-1.9.20.jar:?]
at io.debezium.connector.db2as400.As400StreamingChangeEventSource.lambda$processJournalEntries$0(As400StreamingChangeEventSource.java:250) ~[classes/:?]
at io.debezium.connector.db2as400.As400RpcConnection.getJournalEntries(As400RpcConnection.java:143) ~[classes/:?]
at io.debezium.connector.db2as400.As400StreamingChangeEventSource.execute(As400StreamingChangeEventSource.java:116) ~[classes/:?]
at io.debezium.connector.db2as400.As400StreamingChangeEventSource.execute(As400StreamingChangeEventSource.java:45) ~[classes/:?]
at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174) ~[debezium-core-2.2.1.Final.jar:2.2.1.Final]
at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141) ~[debezium-core-2.2.1.Final.jar:2.2.1.Final]
at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109) ~[debezium-core-2.2.1.Final.jar:2.2.1.Final]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:833) [?:?]

[msillence]

That's odd the only type that results in zonedDecimal is NUMERIC, which we use extensively

I wonder if it's something magic about the parameters of your column.

You can check the column type with:

SELECT data_type,length,numeric_scale FROM qsys2.SYSCOLUMNS where table_schema='<schema/lib>' and table_name='<long_table_name>';

filling in the appropriate <schema/lib> and <long_table_name> for your table

please can you see if you can recreate the issue with some sql you could send me

e.g.

create table test.numtest(n1 numeric(<length>, <scale>));

insert into test.numtest (n1) values (<value triggering issue>);

you can configure this as the only table to include in debezium so the existing problem doesn't triger first using the "table.include.list": "TEST.NUMTEST",

[SaurabhNair239]

We tried with the same table structure provided by you and it is working. Even we have checked the parameters of our column and it also looks fine.

Is it possible log the full record in debezium rather than just bytes. So that we can compare the data how it looks in journal and in debezium ?

[msillence]

we simply read the journal, I have code to dump the journal record but you can get that anyway, I did mean to make it do that when we had issues such as this, I could do a release with this change

[msillence]

I've been reading up on this and it seems there are two formats zoned decimal and packed decimal
From what I've read it seems that columns of type number should be zoned decimal and columns of type decimal should be packed decimal
Is it possible you're forcing packed decimal in this column?
does the iseries correctly display the values if you select the column with a sql query?

[msillence]

One thing I'd like to check, has the table changed recently - there is a limitation that if the connector isn't running and the table changes it loads the new state and can't decode the old journal entries
Apparently I need to add support for historic schemas to this implementation which should help
IBM won't release the format of the journal entries for schema changes so our ability to work with multiple table changes would still be limited but could be better than it is

[SaurabhNair239]

The historical record are getting retrieved as the kafka message from the debezium the real issue starts when we try to insert the data in the real time it throws an error as mentioned before.

[msillence]

this is not so much the changes to the records (inserts/updates/deletes) as changes to the schema
are you changing the schema?

[msillence]

It occured to me last night that maybe the problem isn't the number column but the column before

The buffer we decode has no field delimeters so if we get the length wrong on a prior column we will be trying to extract data from the wrong place in the buffer and it probably won't be valid

Please could you run the following sql:

SELECT ordinal_position, data_type, LENGTH, numeric_scale, numeric_precision, character_maximum_length, character_octet_length, numeric_precision_radix, datetime_precision, user_defined_type_schema, user_defined_type_name 
 FROM QSYS2.SYSCOLUMNS
WHERE TABLE_SCHEMA='<schema>' and table_name='<table>'
ORDER BY ordinal_position asc;

I'm not expecting anything in the user_defined parts, it shouldn't expose anything sensitve I'm mostly interested in types and lengths

[SaurabhNair239]

We ran the above mentioned SQL query and didn't find any special things in the user_defined parts along with this message I have attached the csv file which contains the column data type and its lengths.

SELECT ENTRY_TIMESTAMP AS ENTRY,JOURNAL_CODE AS JRNCODE, CASE WHEN JOURNAL_ENTRY_TYPE = 'PT' THEN 'INSERT' WHEN JOURNAL_ENTRY_TYPE = 'PX'
                           THEN 'INSERT BY RRN'
                         WHEN JOURNAL_ENTRY_TYPE = 'UB'
                           THEN 'UPDATE BEFORE'
                         WHEN JOURNAL_ENTRY_TYPE = 'UP'
                           THEN 'UPDATE AFTER'
                         WHEN JOURNAL_ENTRY_TYPE = 'DL'
                           THEN 'DELETE'
                         ELSE JOURNAL_ENTRY_TYPE
                    END AS JRNTYPE,
                    JOB_NAME AS JOBNAME,
                    JOB_USER AS JOBUSER,
                    JOB_NUMBER AS JOBNBR,
                    SUBSTR(OBJECT,1,10) AS FILE,
                    SUBSTR(OBJECT,11,10) AS FILELIB,
                    SUBSTR(OBJECT,21,10) AS FILEMBR,
                    OBJECT_TYPE AS OBJTYPE,
                    PROGRAM_NAME AS PGMNAME,
                    PROGRAM_LIBRARY AS PGMLIB,
                    CAST(ENTRY_DATA AS CHAR(2000)),
                    SEQUENCE_NUMBER AS SEQNBR
                    FROM TABLE(DISPLAY_JOURNAL('JRNLIB',
                                               'xxxxxx',
                             OBJECT_LIBRARY => 'xxxxxx',
                                OBJECT_NAME => 'xxxxxx',
                              OBJECT_MEMBER => 'xxxxxx',
                             OBJECT_OBJTYPE => '*FILE'))

We have checked the journal file using the following query but we found the buffer position to be fine.

At least we can say that the column_number 90 is the buffer position which shows an error. So it will be best if we can compare the buffer from debezium with the journal records.

SYSCOLUMNS_202312051221.csv

[msillence]

Oh you have some graphic types, I think they might be the problem

[msillence]

OK I'm sure it's the grapic types, currently if we don't recognise the type I treat it as binary with the lenght of the column, graphic seems to be some form of unicode and is two bytes per length. so I expect after the first graphic column we have 1/2 that column left as we try and process it as if it were the next column

[msillence]

This should fix it I think: #69

Is graphic simply for unicode ucs2/utf16 - it looks like the newer versions of db2 (11) has 4 byte variants as well as 2 byte but that's not available for the iseries

[msillence]

I've pushed image silllencem/debezium-connector-ibmi:2.4.0.Final_1.10.5 if you want to try it

[SaurabhNair239]

Thank you so much!!! It is working now with this version.