search

confluentinc / kafka-connect-jdbc

Kafka Connect connector for JDBC-compatible databases
Other
1.01k stars 953 forks source link

connect-standalone got hang at after (org.apache.kafka.connect.runtime.ConnectorConfig$EnrichedConnectorConfig:376) #1320

Open addios41 opened 1 year ago

addios41 commented 1 year ago

I tried to start connect-standalone to connect to mySQL. When starting, it got hang as per the log and nothing showed up. 

[2023-03-14 14:43:49,701] INFO [jdbc_source_mysql_03|worker] Attempting to open connection #1 to MySql (io.confluent.connect.jdbc.util.CachedConnectionProvider:80)
[2023-03-14 14:43:49,702] INFO [jdbc_source_mysql_03|worker] --------------- START GETTING CONNECTION (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:250)
[2023-03-14 14:43:50,118] INFO [jdbc_source_mysql_03|worker] --------------- STOP GETTING CONNECTION (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:252)
[2023-03-14 14:43:50,121] INFO [jdbc_source_mysql_03|worker] Starting thread to monitor tables. (io.confluent.connect.jdbc.source.TableMonitorThread:82)
[2023-03-14 14:43:50,123] DEBUG [jdbc_source_mysql_03|worker] Using MySql dialect to check support for [TABLE] (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:481)
[2023-03-14 14:43:50,124] INFO SourceConnectorConfig values: 
        config.action.reload = restart
        connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
        errors.log.enable = true
        errors.log.include.messages = false
        errors.retry.delay.max.ms = 60000
        errors.retry.timeout = 0
        errors.tolerance = none
        header.converter = null
        key.converter = null
        name = jdbc_source_mysql_03
        predicates = []
        tasks.max = 1
        topic.creation.groups = []
        transforms = []
        value.converter = null
 (org.apache.kafka.connect.runtime.SourceConnectorConfig:376)
[2023-03-14 14:43:50,125] INFO EnrichedConnectorConfig values: 
        config.action.reload = restart
        connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
        errors.log.enable = true
        errors.log.include.messages = false
        errors.retry.delay.max.ms = 60000
        errors.retry.timeout = 0
        errors.tolerance = none
        header.converter = null
        key.converter = null
        name = jdbc_source_mysql_03
        predicates = []
        tasks.max = 1
        topic.creation.groups = []
        transforms = []
        value.converter = null
 (org.apache.kafka.connect.runtime.ConnectorConfig$EnrichedConnectorConfig:376)
[2023-03-14 14:43:50,132] DEBUG [jdbc_source_mysql_03|worker] Used MySql dialect to find table types: [TABLE] (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:500)
[2023-03-14 14:43:50,132] DEBUG [jdbc_source_mysql_03|worker] Using MySql dialect to get TABLE (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:429)
[2023-03-14 14:43:50,156] DEBUG [jdbc_source_mysql_03|worker] Used MySql dialect to find 1 TABLE (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:442)
[2023-03-14 14:43:50,157] DEBUG [jdbc_source_mysql_03|worker] Got the following tables: ["mytestdb"."test11"] (io.confluent.connect.jdbc.source.TableMonitorThread:176)
[2023-03-14 14:43:50,157] INFO [jdbc_source_mysql_03|worker] --------------- START GETTING CONNECTION (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:250)
[2023-03-14 14:43:50,183] INFO [jdbc_source_mysql_03|worker] --------------- STOP GETTING CONNECTION (io.confluent.connect.jdbc.dialect.GenericDatabaseDialect:252)
[2023-03-14 14:43:50,185] INFO [jdbc_source_mysql_03|worker] SourceConnectorConfig values: 
        config.action.reload = restart
        connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
        errors.log.enable = true
        errors.log.include.messages = false
        errors.retry.delay.max.ms = 60000
        errors.retry.timeout = 0
        errors.tolerance = none
        header.converter = null
        key.converter = null
        name = jdbc_source_mysql_03
        predicates = []
        tasks.max = 1
        topic.creation.groups = []
        transforms = []
        value.converter = null
 (org.apache.kafka.connect.runtime.SourceConnectorConfig:376)
[2023-03-14 14:43:50,189] INFO [jdbc_source_mysql_03|worker] EnrichedConnectorConfig values: 
        config.action.reload = restart
        connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
        errors.log.enable = true
        errors.log.include.messages = false
        errors.retry.delay.max.ms = 60000
        errors.retry.timeout = 0
        errors.tolerance = none
        header.converter = null
        key.converter = null
        name = jdbc_source_mysql_03
        predicates = []
        tasks.max = 1
        topic.creation.groups = []
        transforms = []
        value.converter = null
 (org.apache.kafka.connect.runtime.ConnectorConfig$EnrichedConnectorConfig:376)
[2023-03-14 14:43:50,187] DEBUG [jdbc_source_mysql_03|worker] Based on the supplied filtering rules, the tables available to read from include: `mytestdb`.`test11` (io.confluent.connect.jdbc.source.TableMonitorThread:127)
[2023-03-14 14:43:50,190] DEBUG [jdbc_source_mysql_03|worker] Based on the supplied filtering rules, the tables available to read from include: `mytestdb`.`test11` (io.confluent.connect.jdbc.source.TableMonitorThread:127)
[2023-03-14 14:53:48,918] DEBUG node0 scavenging sessions (org.eclipse.jetty.server.session:241)
[2023-03-14 14:53:48,918] DEBUG org.eclipse.jetty.server.session.SessionHandler2025928493==dftMaxIdleSec=-1 scavenging sessions (org.eclipse.jetty.server.session:1251)
[2023-03-14 14:53:48,919] DEBUG org.eclipse.jetty.server.session.SessionHandler2025928493==dftMaxIdleSec=-1 scavenging session ids [] (org.eclipse.jetty.server.session:1259)
[2023-03-14 14:53:48,919] DEBUG org.eclipse.jetty.server.session.DefaultSessionCache@44bd4b0a[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] checking expiration on [] (org.eclipse.jetty.server.session:688)

connect-standalone.properties


bootstrap.servers=172.22.10.21:9092,172.22.10.22:9092,172.22.10.23:9092

key.converter=org.apache.kafka.connect.json.JsonConverter
value.converter=org.apache.kafka.connect.json.JsonConverter
key.converter.schemas.enable=true
value.converter.schemas.enable=true

offset.storage.file.filename=/tmp/connect.offsets
offset.flush.interval.ms=10000

plugin.path=/app/plugin

source-connector.properties

name=jdbc_source_mysql_03
connector.class=io.confluent.connect.jdbc.JdbcSourceConnector
connection.url=jdbc:mysql://172.22.10.24:3306/mytestdb
connection.user=mytest
connection.password=password
numeric.mapping=best_fit
tasks.max=1
mode=incrementing
#timestamp.column.name=modifiedAt
incrementing.column.name=id
table.whitelist=mytestdb.test11
table.types=TABLE
timestamp.initial=-1
topic.prefix=mysql1.mytestdb.
table.poll.interval.ms=5000
errors.log.enable=true
addios41 commented 1 year ago

I open a new terminal and start connect-standalone. It worked, somehow. Not sure if anyone knows a reason and how to fix?

ekisu commented 1 year ago

I've ran at the same issue while using an MySQL connector, and attaching a debugger seems to indicate some kind of deadlock while creating the source connectors:

"pool-3-thread-1@6805" prio=5 tid=0x33 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     blocks Thread-30@6807
     waiting for Thread-30@6807 to release lock on <0x1aa6> (a org.apache.kafka.connect.runtime.standalone.StandaloneHerder)
      at org.apache.kafka.connect.runtime.standalone.StandaloneHerder$ConfigUpdateListener.onTaskConfigUpdate(StandaloneHerder.java:391)
      at org.apache.kafka.connect.storage.MemoryConfigBackingStore.putTaskConfigs(MemoryConfigBackingStore.java:129)
      - locked <0x1ac8> (a org.apache.kafka.connect.storage.MemoryConfigBackingStore)
      at org.apache.kafka.connect.runtime.standalone.StandaloneHerder.updateConnectorTasks(StandaloneHerder.java:358)
      at org.apache.kafka.connect.runtime.standalone.StandaloneHerder.lambda$null$3(StandaloneHerder.java:240)
      at org.apache.kafka.connect.runtime.standalone.StandaloneHerder$$Lambda$561.1643241998.run(Unknown Source:-1)
      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
      at java.util.concurrent.FutureTask.run(FutureTask.java:264)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:829)
[...]
"Thread-30@6807" prio=5 tid=0x35 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     blocks pool-3-thread-1@6805
     waiting for pool-3-thread-1@6805 to release lock on <0x1ac8> (a org.apache.kafka.connect.storage.MemoryConfigBackingStore)
      at org.apache.kafka.connect.storage.MemoryConfigBackingStore.putTaskConfigs(MemoryConfigBackingStore.java:121)
      at org.apache.kafka.connect.runtime.standalone.StandaloneHerder.updateConnectorTasks(StandaloneHerder.java:358)
      at org.apache.kafka.connect.runtime.standalone.StandaloneHerder.requestTaskReconfiguration(StandaloneHerder.java:255)
      - locked <0x1aa6> (a org.apache.kafka.connect.runtime.standalone.StandaloneHerder)
      at org.apache.kafka.connect.runtime.HerderConnectorContext.requestTaskReconfiguration(HerderConnectorContext.java:50)
      at org.apache.kafka.connect.runtime.WorkerConnector$WorkerConnectorContext.requestTaskReconfiguration(WorkerConnector.java:501)
      at io.confluent.connect.jdbc.source.TableMonitorThread.run(TableMonitorThread.java:86)

Here's the full report I've obtained from the debugger: threads_report.txt.

Also, it doesn't seem to hang every time, but it happens quite often; killing the Java process and restarting it will make it work eventually

jamesnyika commented 1 year ago

Has anyone found a way to fix this ? I have exactly the same symptoms: periodically works .. but mostly does not. Connector never goes into a running state .. just hangs.

jamesnyika commented 1 year ago

Temporary workaround : I switched to using the aiven JDBC connector and it seems to currently be free of this deadlock problem.
get the latest release here (on the right side panel: v 6.8.0 as of today) : https://github.com/aiven/jdbc-connector-for-apache-kafka The only things I changed in my configurations were to use its entire folder of jars rather than confluent's... and their class name is different : io.aiven.connect.jdbc.JdbcSourceConnector

Works smoothly with most of the same options as the confluent one

kamalnigam commented 1 year ago

Hi, Any one found a way to fix this issue? I am getting the same issue and using the latest version of all jars & java.

kamalnigam commented 1 year ago

just want to share that i switch to "kafka-connect-jdbc-10.3.0" working fine with this jar. so may be some deadlock issue in the lastest version of jar.

kentangditaman commented 10 months ago

I have same problem. In config i am using table.whitelist, when i using topic.prefix it will be hang. After i remove topic.prefix from config, it will be fine. Temporary solution just remove topic.prefix. I think it is a bug that need repair.

Kukunin commented 7 months ago

Happens to me as well. When I remove topic.prefix it says:

Connector configuration is invalid and contains the following 1 error(s):
The 'topic.prefix' value is invalid: A value is required
You can also find the above list of errors at the endpoint `/connector-plugins/{connectorType}/config/validate`
DavidP-Vitro commented 4 weeks ago

just want to share that i switch to "kafka-connect-jdbc-10.3.0" working fine with this jar. so may be some deadlock issue in the lastest version of jar.

I was having this issue with the latest version (10.7.6) so I tried 10.3.6 and still got the error. Using 10.3.0 works though.

I thought I had a fix before then because I had been loading the config file during connect startup, and the first time I tried starting connect first, then adding the connector after startup it worked. Seems to have been a fluke though since the next 3 times I tried that it failed with the same deadlock issue.