To add to my own comments 😊
I’ve put debug on to the adapter that’s failing more than the others and I
observe that sometimes it fails to start up and sometimes it doesn’t. Either
way the call back to the REST interface to tell it that it can return back to
the API doesn’t work and the original HTTP call timesout.
When it does fail to startup the whole REST API dies and goes unresponsive –
all HTTP calls timeout with no response i.e. a query to see what connectors are
working.
Is there documentation showing all the various threads/lambdas at play here?
Thanks,
John.
From: talljhawk...@gmail.com <talljhawk...@gmail.com>
Sent: Wednesday, May 29, 2024 2:57 PM
To: dev@kafka.apache.org
Subject: standalone race condition?
Hi Folks,
I quite often get this issue with the kafka standalone and I really need it
fixing as I can’t continue working like this so any help would be gratefully
received…
Scenario:
Server starts OK.
Deploy a connector or two using the REST API.
Then I deploy the JDBC connector and sometimes it deploys OK and sometimes it
doesn’t – more usually doesn’t. When this happens, I then can’t use the REST
API at all – it doesn’t accept any more connections – or at least it doesn’t
seem to. The below trace is deploying the connector when it’s failing – I had
literally just deployed it into the same standalone instance and then deleted
it and it had all worked fine but this time it decided not to. When it works,
it works just fine ! It seems to be something blocking it from recognising that
the connector has actually started OK – like one of the many lambda callbacks
didn’t work or was mistimed so that a wait happened after a notify on a thread
and so the wait just sticks there? I’ve looked at the standalone code and can’t
figure it out – but there’s a lot going on ! I don’t believe that this is the
connectors fault as I’ve had this issue before on other connectors – it just
seems to happen more on this connector – perhaps the connector calls-back too
quickly or too slowly?
Thanks for any help,
John.
[2024-05-29 14:47:04,335] DEBUG Getting plugin class loader:
'PluginClassLoader{pluginLocation=file:/C:/opsis/connectors/opsis-sagex3-connector-0.1.0-SNAPSHOT.jar}'
for connector: io.confluent.connect.jdbc.JdbcSourceConnector
(org.apache.kafka.connect.runtime.isolation.DelegatingClassLoader:94)
[2024-05-29 14:47:04,336] INFO JdbcSourceConnectorConfig values:
batch.max.rows = 100
catalog.pattern = null
connection.attempts = 3
connection.backoff.ms = 10000
connection.password = [hidden]
connection.url = [hidden]
connection.user = [hidden]
db.timezone = UTC
dialect.name =
incrementing.column.name = ROWID
mode = timestamp+incrementing
numeric.mapping = null
numeric.precision.mapping = false
poll.interval.ms = 5000
query =
query.retry.attempts = -1
query.suffix =
quote.sql.identifiers = ALWAYS
schema.pattern = [hidden]
table.blacklist = []
table.monitoring.startup.polling.limit.ms = 10000
table.poll.interval.ms = 60000
table.types = [VIEW]
table.whitelist = [hidden]
timestamp.column.name = [hidden]
timestamp.delay.interval.ms = 0
timestamp.granularity = connect_logical
timestamp.initial = 1714518000000
topic.prefix =
transaction.isolation.mode = DEFAULT
validate.non.null = false
(io.confluent.connect.jdbc.source.JdbcSourceConnectorConfig:370)
[2024-05-29 14:47:04,338] INFO AbstractConfig values:
(org.apache.kafka.common.config.AbstractConfig:370)
[2024-05-29 14:47:04,339] DEBUG [SageX3Connector|worker] Getting plugin class
loader:
'PluginClassLoader{pluginLocation=file:/C:/opsis/connectors/opsis-sagex3-connector-0.1.0-SNAPSHOT.jar}'
for connector: io.confluent.connect.jdbc.JdbcSourceConnector
(org.apache.kafka.connect.runtime.isolation.DelegatingClassLoader:94)
[2024-05-29 14:47:04,339] INFO [SageX3Connector|worker] Creating connector
SageX3Connector of type io.confluent.connect.jdbc.JdbcSourceConnector
(org.apache.kafka.connect.runtime.Worker:309)
[2024-05-29 14:47:04,340] INFO [SageX3Connector|worker] SourceConnectorConfig
values:
config.action.reload = restart
connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
errors.log.enable = false
errors.log.include.messages = false
errors.retry.delay.max.ms = 60000
errors.retry.timeout = 0
errors.tolerance = none
exactly.once.support = requested
header.converter = null
key.converter = null
name = SageX3Connector
offsets.storage.topic = null
predicates = []
tasks.max = 1
topic.creation.groups = []
transaction.boundary = poll
transaction.boundary.interval.ms = null
transforms = []
value.converter = null
(org.apache.kafka.connect.runtime.SourceConnectorConfig:370)
[2024-05-29 14:47:04,340] INFO [SageX3Connector|worker] EnrichedConnectorConfig
values:
config.action.reload = restart
connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
errors.log.enable = false
errors.log.include.messages = false
errors.retry.delay.max.ms = 60000
errors.retry.timeout = 0
errors.tolerance = none
exactly.once.support = requested
header.converter = null
key.converter = null
name = SageX3Connector
offsets.storage.topic = null
predicates = []
tasks.max = 1
topic.creation.groups = []
transaction.boundary = poll
transaction.boundary.interval.ms = null
transforms = []
value.converter = null
(org.apache.kafka.connect.runtime.ConnectorConfig$EnrichedConnectorConfig:370)
[2024-05-29 14:47:04,341] INFO [SageX3Connector|worker] Instantiated connector
SageX3Connector with version 10.7.4 of type class
io.confluent.connect.jdbc.JdbcSourceConnector
(org.apache.kafka.connect.runtime.Worker:331)
[2024-05-29 14:47:04,341] INFO [SageX3Connector|worker] Finished creating
connector SageX3Connector (org.apache.kafka.connect.runtime.Worker:352)
[2024-05-29 14:47:04,341] DEBUG [SageX3Connector|worker]
WorkerConnector{id=SageX3Connector} Initializing connector SageX3Connector
(org.apache.kafka.connect.runtime.WorkerConnector:167)
[2024-05-29 14:47:04,342] DEBUG [SageX3Connector|worker]
WorkerConnector{id=SageX3Connector} Transition connector to STARTED
(org.apache.kafka.connect.runtime.WorkerConnector:369)
[2024-05-29 14:47:04,342] INFO [SageX3Connector|worker] Starting JDBC Source
Connector (io.confluent.connect.jdbc.JdbcSourceConnector:71)
[2024-05-29 14:47:04,343] INFO [SageX3Connector|worker]
JdbcSourceConnectorConfig values:
batch.max.rows = 100
catalog.pattern = null
connection.attempts = 3
connection.backoff.ms = 10000
connection.password = [hidden]
connection.url = [hidden]
connection.user = [hidden]
db.timezone = UTC
dialect.name =
incrementing.column.name = ROWID
mode = timestamp+incrementing
numeric.mapping = null
numeric.precision.mapping = false
poll.interval.ms = 5000
query =
query.retry.attempts = -1
query.suffix =
quote.sql.identifiers = ALWAYS
schema.pattern = [hidden]
table.blacklist = []
table.monitoring.startup.polling.limit.ms = 10000
table.poll.interval.ms = 60000
table.types = [VIEW]
table.whitelist = [hidden]
timestamp.column.name = [hidden]
timestamp.delay.interval.ms = 0
timestamp.granularity = connect_logical
timestamp.initial = 1714518000000
topic.prefix =
transaction.isolation.mode = DEFAULT
validate.non.null = false
(io.confluent.connect.jdbc.source.JdbcSourceConnectorConfig:370)
[2024-05-29 14:47:04,343] INFO [SageX3Connector|worker] Validating JDBC URL.
(io.confluent.connect.jdbc.dialect.DatabaseDialects:171)
[2024-05-29 14:47:04,344] INFO [SageX3Connector|worker] Validated JDBC URL.
(io.confluent.connect.jdbc.dialect.DatabaseDialects:174)
[2024-05-29 14:47:04,344] INFO [SageX3Connector|worker] Validating JDBC URL.
(io.confluent.connect.jdbc.dialect.DatabaseDialects:171)
[2024-05-29 14:47:04,345] INFO [SageX3Connector|worker] Validated JDBC URL.
(io.confluent.connect.jdbc.dialect.DatabaseDialects:174)
[2024-05-29 14:47:04,345] INFO [SageX3Connector|worker] Initial connection
attempt with the database. (io.confluent.connect.jdbc.JdbcSourceConnector:94)
[2024-05-29 14:47:04,369] INFO [SageX3Connector|worker] Starting thread to
monitor tables. (io.confluent.connect.jdbc.source.TableMonitorThread:82)
[2024-05-29 14:47:04,369] INFO SourceConnectorConfig values:
config.action.reload = restart
connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
errors.log.enable = false
errors.log.include.messages = false
errors.retry.delay.max.ms = 60000
errors.retry.timeout = 0
errors.tolerance = none
exactly.once.support = requested
header.converter = null
key.converter = null
name = SageX3Connector
offsets.storage.topic = null
predicates = []
tasks.max = 1
topic.creation.groups = []
transaction.boundary = poll
transaction.boundary.interval.ms = null
transforms = []
value.converter = null
(org.apache.kafka.connect.runtime.SourceConnectorConfig:370)
[2024-05-29 14:47:04,372] INFO EnrichedConnectorConfig values:
config.action.reload = restart
connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
errors.log.enable = false
errors.log.include.messages = false
errors.retry.delay.max.ms = 60000
errors.retry.timeout = 0
errors.tolerance = none
exactly.once.support = requested
header.converter = null
key.converter = null
name = SageX3Connector
offsets.storage.topic = null
predicates = []
tasks.max = 1
topic.creation.groups = []
transaction.boundary = poll
transaction.boundary.interval.ms = null
transforms = []
value.converter = null
(org.apache.kafka.connect.runtime.ConnectorConfig$EnrichedConnectorConfig:370)
[2024-05-29 14:47:04,425] DEBUG Connector SageX3Connector task count changed
from 0 to 1 (org.apache.kafka.connect.runtime.AbstractHerder:852)
[2024-05-29 14:47:04,425] INFO [SageX3Connector|worker] SourceConnectorConfig
values:
config.action.reload = restart
connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
errors.log.enable = false
errors.log.include.messages = false
errors.retry.delay.max.ms = 60000
errors.retry.timeout = 0
errors.tolerance = none
exactly.once.support = requested
header.converter = null
key.converter = null
name = SageX3Connector
offsets.storage.topic = null
predicates = []
tasks.max = 1
topic.creation.groups = []
transaction.boundary = poll
transaction.boundary.interval.ms = null
transforms = []
value.converter = null
(org.apache.kafka.connect.runtime.SourceConnectorConfig:370)
[2024-05-29 14:47:04,426] DEBUG Reconfiguring connector SageX3Connector:
writing new updated configurations for tasks
(org.apache.kafka.connect.runtime.AbstractHerder:864)
[2024-05-29 14:47:04,428] INFO [SageX3Connector|worker] EnrichedConnectorConfig
values:
config.action.reload = restart
connector.class = io.confluent.connect.jdbc.JdbcSourceConnector
errors.log.enable = false
errors.log.include.messages = false
errors.retry.delay.max.ms = 60000
errors.retry.timeout = 0
errors.tolerance = none
exactly.once.support = requested
header.converter = null
key.converter = null
name = SageX3Connector
offsets.storage.topic = null
predicates = []
tasks.max = 1
topic.creation.groups = []
transaction.boundary = poll
transaction.boundary.interval.ms = null
transforms = []
value.converter = null
(org.apache.kafka.connect.runtime.ConnectorConfig$EnrichedConnectorConfig:370)
[2024-05-29 14:47:04,429] DEBUG [SageX3Connector|worker] Connector
SageX3Connector task count changed from 0 to 1
(org.apache.kafka.connect.runtime.AbstractHerder:852)
[2024-05-29 14:47:04,429] DEBUG [SageX3Connector|worker] Reconfiguring
connector SageX3Connector: writing new updated configurations for tasks
(org.apache.kafka.connect.runtime.AbstractHerder:864)
[2024-05-29 14:47:32,460] DEBUG Uncaught exception in REST call to
/connectors/SageX3Connector/config
(org.apache.kafka.connect.runtime.rest.errors.ConnectExceptionMapper:42)
org.apache.kafka.connect.runtime.rest.errors.ConnectRestException: Request
timed out
at
org.apache.kafka.connect.runtime.rest.HerderRequestHandler.completeRequest(HerderRequestHandler.java:89)
