Failed to reconnect issue #74

jakobhaggstrom · 2024-04-11T07:23:33Z

jakobhaggstrom
Apr 11, 2024

Hi, I'm using the AS400 connector from the Debezium website, but I figured I could write about this issue here as well.

I'm trying to get the AS400 debezium connector to work, and I'm encountering a connectivity issue (I think at least...).

The connector manages to connect to the DB, but it fails when it tries to reconnect. See these logs:

2024-04-09 11:19:57,812 INFO [src-migg-singletab7|task-0] Loading the custom topic naming strategy plugin: io.debezium.connector.db2as400.HostnamePrefixNamingScheme (io.debezium.config.CommonConnectorConfig) [task-thread-src-migg-singletab7-0]
2024-04-09 11:19:57,938 INFO [src-migg-singletab7|task-0] [Producer clientId=connector-producer-src-migg-singletab7-0] Cluster ID: WIVxI7FOQ96K0_euDcaXgQ (org.apache.kafka.clients.Metadata) [kafka-producer-network-thread | connector-producer-src-migg-singletab7-0]
2024-04-09 11:19:58,267 INFO [src-migg-singletab7|task-0] No previous offsets found (io.debezium.connector.common.BaseSourceTask) [task-thread-src-migg-singletab7-0]
2024-04-09 11:19:58,267 INFO [src-migg-singletab7|task-0] previous offsets not found creating from config (io.debezium.connector.db2as400.As400ConnectorTask) [task-thread-src-migg-singletab7-0]
2024-04-09 11:19:58,351 INFO [src-migg-singletab7|task-0] create new as400 connection (io.debezium.connector.db2as400.As400RpcConnection) [task-thread-src-migg-singletab7-0]
2024-04-09 11:19:58,369 ERROR [src-migg-singletab7|task-0] Failed to reconnect (io.debezium.connector.db2as400.As400RpcConnection) [task-thread-src-migg-singletab7-0]
java.net.ConnectException: Connection refused
at java.base/sun.nio.ch.Net.connect0(Native Method)
at java.base/sun.nio.ch.Net.connect(Net.java:579)
at java.base/sun.nio.ch.Net.connect(Net.java:568)
at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:593)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
at java.base/java.net.Socket.connect(Socket.java:633)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at com.ibm.as400.access.PortMapper.getSocketConnection(PortMapper.java:272)
at com.ibm.as400.access.PortMapper.getServerSocket(PortMapper.java:205)
at com.ibm.as400.access.PortMapper.getServerSocket(PortMapper.java:129)
at com.ibm.as400.access.AS400ImplRemote.signonConnect(AS400ImplRemote.java:3522)
at com.ibm.as400.access.AS400ImplRemote.signon(AS400ImplRemote.java:3316)
at com.ibm.as400.access.AS400.sendSignonRequest(AS400.java:3726)
at com.ibm.as400.access.AS400.promptSignon(AS400.java:3281)
at com.ibm.as400.access.AS400.signon(AS400.java:4650)
at com.ibm.as400.access.AS400.connectService(AS400.java:1596)
at com.ibm.as400.access.AS400.connectService(AS400.java:1553)
at io.debezium.connector.db2as400.As400RpcConnection.connection(As400RpcConnection.java:113)
at io.debezium.connector.db2as400.As400RpcConnection.(As400RpcConnection.java:62)
at io.debezium.connector.db2as400.As400ConnectorTask.start(As400ConnectorTask.java:116)
at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:227)
at org.apache.kafka.connect.runtime.AbstractWorkerSourceTask.initializeAndStart(AbstractWorkerSourceTask.java:274)
at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:200)
at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:257)
at org.apache.kafka.connect.runtime.AbstractWorkerSourceTask.run(AbstractWorkerSourceTask.java:75)
at org.apache.kafka.connect.runtime.isolation.Plugins.lambda$withClassLoader$1(Plugins.java:177)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
2024-04-09 11:19:58,369 ERROR [src-migg-singletab7|task-0] Failed to fetch library (io.debezium.connector.db2as400.As400RpcConnection) [task-thread-src-migg-singletab7-0]
java.io.IOException: Failed to reconnect
at io.debezium.connector.db2as400.As400RpcConnection.connection(As400RpcConnection.java:117)
at io.debezium.connector.db2as400.As400RpcConnection.(As400RpcConnection.java:62)
at io.debezium.connector.db2as400.As400ConnectorTask.start(As400ConnectorTask.java:116)
at io.debezium.connector.common.BaseSourceTask.start(BaseSourceTask.java:227)
at org.apache.kafka.connect.runtime.AbstractWorkerSourceTask.initializeAndStart(AbstractWorkerSourceTask.java:274)
at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:200)
at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:257)
at org.apache.kafka.connect.runtime.AbstractWorkerSourceTask.run(AbstractWorkerSourceTask.java:75)
at org.apache.kafka.connect.runtime.isolation.Plugins.lambda$withClassLoader$1(Plugins.java:177)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: java.net.ConnectException: Connection refused
at java.base/sun.nio.ch.Net.connect0(Native Method)
at java.base/sun.nio.ch.Net.connect(Net.java:579)
at java.base/sun.nio.ch.Net.connect(Net.java:568)
at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:593)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
at java.base/java.net.Socket.connect(Socket.java:633)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at com.ibm.as400.access.PortMapper.getSocketConnection(PortMapper.java:272)
at com.ibm.as400.access.PortMapper.getServerSocket(PortMapper.java:205)
at com.ibm.as400.access.PortMapper.getServerSocket(PortMapper.java:129)
at com.ibm.as400.access.AS400ImplRemote.signonConnect(AS400ImplRemote.java:3522)
at com.ibm.as400.access.AS400ImplRemote.signon(AS400ImplRemote.java:3316)
at com.ibm.as400.access.AS400.sendSignonRequest(AS400.java:3726)
at com.ibm.as400.access.AS400.promptSignon(AS400.java:3281)
at com.ibm.as400.access.AS400.signon(AS400.java:4650)
at com.ibm.as400.access.AS400.connectService(AS400.java:1596)
at com.ibm.as400.access.AS400.connectService(AS400.java:1553)
at io.debezium.connector.db2as400.As400RpcConnection.connection(As400RpcConnection.java:113)
... 13 more
I'm not sure whether this is a connectivity or permission issue, because I get the Failed to fetch library together with the Failed to reconnect error. However, the connector continues after this error, and lists all the captured tables, and finally crashes with a similar error: (continues in next post)

Jakob Häggström:
..
2024-04-09 11:19:59,998 INFO [src-migg-singletab7|task-0] Adding table db.schema.tablename to the list of capture schema tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
2024-04-09 11:20:00,009 INFO [src-migg-singletab7|task-0] Created connection pool with 1 threads (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
2024-04-09 11:20:00,009 INFO [src-migg-singletab7|task-0] Snapshot step 3 - Locking captured tables [db.schema.table] (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
2024-04-09 11:20:00,009 INFO [src-migg-singletab7|task-0] Snapshot step 4 - Determining snapshot offset (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
2024-04-09 11:20:00,009 INFO [src-migg-singletab7|task-0] create new as400 connection (io.debezium.connector.db2as400.As400RpcConnection) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
2024-04-09 11:20:00,009 INFO [src-migg-singletab7|task-0] Disconnecting (io.debezium.connector.db2as400.As400RpcConnection) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
2024-04-09 11:20:00,019 ERROR [src-migg-singletab7|task-0] Failed to reconnect (io.debezium.connector.db2as400.As400RpcConnection) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
java.net.ConnectException: Connection refused
at java.base/sun.nio.ch.Net.connect0(Native Method)
at java.base/sun.nio.ch.Net.connect(Net.java:579)
at java.base/sun.nio.ch.Net.connect(Net.java:568)
at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:593)
at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
at java.base/java.net.Socket.connect(Socket.java:633)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at com.ibm.as400.access.PortMapper.getSocketConnection(PortMapper.java:272)
at com.ibm.as400.access.PortMapper.getServerSocket(PortMapper.java:205)
at com.ibm.as400.access.PortMapper.getServerSocket(PortMapper.java:129)
at com.ibm.as400.access.AS400ImplRemote.signonConnect(AS400ImplRemote.java:3522)
at com.ibm.as400.access.AS400ImplRemote.signon(AS400ImplRemote.java:3316)
at com.ibm.as400.access.AS400.sendSignonRequest(AS400.java:3726)
at com.ibm.as400.access.AS400.promptSignon(AS400.java:3281)
at com.ibm.as400.access.AS400.signon(AS400.java:4650)
at com.ibm.as400.access.AS400.connectService(AS400.java:1596)
at com.ibm.as400.access.AS400.connectService(AS400.java:1553)
at io.debezium.connector.db2as400.As400RpcConnection.connection(As400RpcConnection.java:113)
at io.debezium.connector.db2as400.As400RpcConnection.getCurrentPosition(As400RpcConnection.java:125)
at io.debezium.connector.db2as400.As400SnapshotChangeEventSource.determineSnapshotOffset(As400SnapshotChangeEventSource.java:139)
at io.debezium.connector.db2as400.As400SnapshotChangeEventSource.determineSnapshotOffset(As400SnapshotChangeEventSource.java:38)
at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:151)
at io.debezium.pipeline.source.AbstractSnapshotChangeEventSource.execute(AbstractSnapshotChangeEventSource.java:94)
at io.debezium.connector.db2as400.As400SnapshotChangeEventSource.execute(As400SnapshotChangeEventSource.java:80)
at io.debezium.connector.db2as400.As400SnapshotChangeEventSource.execute(As400SnapshotChangeEventSource.java...
2024-04-09 11:20:00,020 ERROR [src-migg-singletab7|task-0] Error during snapshot (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-as400rpcconnector-SRC_MIGGTEST__-change-event-source-coordinator]
io.debezium.connector.db2as400.As400RpcConnection$RpcException: Failed to find offset
at io.debezium.connector.db2as400.As400RpcConnection.getCurrentPosition(As400RpcConnection.java:130)
at io.debezium.connector.db2as400.As400SnapshotChangeEventSource.determineSnapshotOffset(As400SnapshotChangeEventSource.java:139)
at io.debezium.connector.db2as400.As400SnapshotChangeEventSource.determineSnapshotOffset(As400SnapshotChangeEventSource.java:38)
at io.debezium.relational.RelationalSnapshotChangeEventSource.doExecute(RelationalSnapshotChangeEventSource.java:151
Caused by: java.io.IOException: Failed to reconnect
at io.debezium.connector.db2as400.As400RpcConnection.connection(As400RpcConnection.java:117)
at io.debezium.connector.db2as400.As400RpcConnection.getCurrentPosition(As400RpcConnection.java:125)
Caused by: java.net.ConnectException: Connection refused
I use this config

{
"connector.class": "io.debezium.connector.db2as400.As400RpcConnector",
"database.hostname": "IP",
"database.user": "usr",
"database.password": "pw",
"database.port" : "portnr",
"database.secure" : "false",
"database.dbname" : "dbname",
"database.schema" : "schema",
"database.keep.alive" : "false",
"database.thread.used" : "true",
"socket.timeout": "1000000",
"topic.prefix": "SRC_MIGGTEST__",
"transforms": "Reroute,changeTopicCase, unwrap, ReplaceField, RenameField,TimestampConverter1, TimestampConverter2",
"table.include.list": "schema.tablename",
"transforms.Reroute.type": "io.debezium.transforms.ByLogicalTableRouter",
"transforms.Reroute.topic.regex": "(.)\.(.)\.(.)\.(.)",
"transforms.Reroute.topic.replacement": "$1$3_$4",
"transforms.changeTopicCase.type": "com.github.jcustenborder.kafka.connect.transform.common.ChangeTopicCase",
"transforms.changeTopicCase.from": "LOWER_UNDERSCORE",
"transforms.changeTopicCase.to": "UPPER_UNDERSCORE",
"transforms.unwrap.type": "io.debezium.transforms.ExtractNewRecordState",
"transforms.unwrap.add.fields": "source.ts_ms,op,table,ts_ms",
"transforms.unwrap.delete.handling.mode": "rewrite",
"transforms.unwrap.drop.tombstones": "true",
"transforms.ReplaceField.type": "org.apache.kafka.connect.transforms.ReplaceField$Value",
"transforms.ReplaceField.exclude": "__deleted",
"transforms.RenameField.type": "org.apache.kafka.connect.transforms.ReplaceField$Value",
"transforms.RenameField.renames": "__source_ts_ms:SRC_OP_TS, __op:SRC_OP_TYPE, __table:SRC_TABLENAME, __ts_ms:INT_CURRENT_TS",
"transforms.TimestampConverter1.type": "org.apache.kafka.connect.transforms.TimestampConverter$Value",
"transforms.TimestampConverter1.field": "SRC_OP_TS",
"transforms.TimestampConverter1.target.type": "Timestamp",
"transforms.TimestampConverter2.type": "org.apache.kafka.connect.transforms.TimestampConverter$Value",
"transforms.TimestampConverter2.field": "INT_CURRENT_TS",
"transforms.TimestampConverter2.target.type": "Timestamp",
"key.converter": "org.apache.kafka.connect.storage.StringConverter",
"key.converter.schemas.enable": "true",
"value.converter": "io.confluent.connect.avro.AvroConverter",
"value.converter.schema.registry.url": "http://cp-cp-schema-registry:8081",
"value.converter.schemas.enable": "true",
"schema.name.adjustment.mode": "avro",
"field.name.adjustment.mode": "avro",
"incremental.snapshot.allow.schema.changes": "true",
"schema.history.internal.kafka.topic": "schemahistorymiggtest.SRC_MIGG",
"schema.history.internal.consumer.security.protocol": "SSL",
"schema.history.internal.consumer.ssl.keystore.location": "sssl",
"schema.history.internal.consumer.ssl.keystore.password": "pw",
"schema.history.internal.consumer.ssl.truststore.location": "ssl",
"schema.history.internal.consumer.ssl.truststore.password": "pw",
"schema.history.internal.kafka.bootstrap.servers": "serv",
"schema.history.internal.producer.security.protocol": "SSL",
"schema.history.internal.producer.ssl.keystore.location": "ssl",
"schema.history.internal.producer.ssl.keystore.password": "pw",
"schema.history.internal.producer.ssl.truststore.location": "ssl",
"schema.history.internal.producer.ssl.truststore.password": "pw",
"errors.log.enable" : "true",
"errors.max.retries" : -1
}
What do you think? Is this problem due to connectivity, or is it due to permissions? Could it be perhaps that cdc is not enabled in the db? The user should have a wide scope of permissions. This connector runs in a kafka-connect environment in openshift.

msillence · 2024-04-11T08:30:33Z

msillence
Apr 11, 2024
Maintainer

It says failed to connect, from the stack trace I'd first check the ports are accessible
https://javadoc.midrange.com/ports.php
you need database 8471 and rpc 8475, this is failing on the rpc connection
The rows Command Call and JDBC are all required - sign on, svrmap, central

0 replies

jakobhaggstrom · 2024-04-12T07:34:24Z

jakobhaggstrom
Apr 12, 2024
Author

Thanks for the response. 😄 Apparently there was a bug somewhere, and we had to set both "database.secure" : "false" "secure" : "false".

On a completely different note, we try to stream from tables with tablenames with Scandiavian letters Å, Ä och Ö. Our JVM uses UTF-8, and the source uses ccsid 278. We try to just include the letter as they are, and we get "Journal not found for db.?T901F error File $T901F in library LFDATA43 not found.". I think the log only prints ASCII letters, hence the ? sign, but i notice the $ sign in $T901F. Do you have any tips and tricks one can do to use Å, Ä och Ö signs? To be specific, to have non-ASCII letters in the table.include.list.

I had one idea that we could maybe find a converter that converts the characters into the IBM standard and use them in the include list. For example, the utf-8 encoded table looks like this, LFDATA43.\u00c5T901F. Do you think it is possible to convert them, but into the IBM standard as well?

1 reply

msillence Apr 12, 2024
Maintainer

There are two things here - logging in java can support utf-8 and the jvm typically uses the environment settings to determine what to do as I remember you can override the default to utf-8 with -Dfile.encoding=UTF-8
The second issue is the naming of things such as journals in ccsid278 and conversion - I think the journal decoding would need to be modified to support ccsid conversion https://github.com/jhc-systems/debezium-connector-ibmi/blob/main/journal-parsing/src/main/java/com/fnz/db2/journal/retrieve/JournalInfoRetrieval.java
Every time we use the AS400Text object we probably need to specify the ccsid or pass in the system so it can automatically detect the ccsid.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Failed to reconnect issue #74

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 2 comments 1 reply

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

Select a reply

Failed to reconnect issue #74

jakobhaggstrom Apr 11, 2024

Replies: 2 comments · 1 reply

msillence Apr 11, 2024 Maintainer

jakobhaggstrom Apr 12, 2024 Author

msillence Apr 12, 2024 Maintainer

jakobhaggstrom
Apr 11, 2024

Replies: 2 comments 1 reply

msillence
Apr 11, 2024
Maintainer

jakobhaggstrom
Apr 12, 2024
Author

msillence Apr 12, 2024
Maintainer