Kafka-connect-jdbc: Kafka connect workers permanently in UNASSIGNED state.

[vamossagar12]

I have a 3 node kafka-connect-jdbc cluster for processing data from Mysql tables. The setup is all fine and it has been pushing data to Kafka.

But the issue is that whenever I check the status of any of the connectors, the status is always UNASSIGNED Owing to this, I can't restart any of the connectors/tasks since I just can't access any of the REST apis to access connectors or tasks. The connectors show as UNASSIGNED even though the workers are in RUNNING states. In cases like these where I am not even able to restart, what should be done to have the tasks/connectors being in RUNNING states? Also, when I add a new worker, it will be in RUNNING state then go back permanently to UNASSGNED state. What Ia m trying to understand is, what should be done to troubleshoot/debug these issues. The REST apis , even though on localhost are just not accessible.

Kafka version is 0.10-cp2

[ewencp]

Do you have some logs showing these transitions to UNASSIGNED state? Normally that should only happen if the connector a) never gets assigned in the first place or b) gets assigned and then the worker running it shuts down and no other worker starts the job and updates its status. Obviously b) shouldn't happen unless there are no workers running yet, which is why I'd be interested in the logs to see if something is going wrong unexpectedly.

re: the version, that's not a version number we would publish since we always use the full 4 numbers + a -cpX to indicate a Confluent-specific version. Is this 0.10.0.1, 0.10.1.X, or 0.10.2.x?

[vamossagar12]

Hi ewen,

Generally the pattern is, when we have 1 kafka-connect worker running and add another one in distributed mode, after few seconds/minutes, we see these lines in the logs:

[2017-04-10 15:06:52,900] ERROR Failed to run query for table TimestampIncrementingTableQuerier{name='bbb_ball_player', query='null', topicPrefix='ci-eng-', timestampColumn='modified', incrementingColumn='id'}:
{}
(io.confluent.connect.jdbc.source.JdbcSourceTask:211)
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1014)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:988)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:974)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1269)
at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1261)
at com.mysql.jdbc.ConnectionImpl.versionMeetsMinimum(ConnectionImpl.java:5509)
at com.mysql.jdbc.Field.getNameNoAliases(Field.java:642)
at com.mysql.jdbc.ResultSetMetaData.getColumnName(ResultSetMetaData.java:256)
at io.confluent.connect.jdbc.source.DataConverter.addFieldSchema(DataConverter.java:90)
at io.confluent.connect.jdbc.source.DataConverter.convertSchema(DataConverter.java:61)
at io.confluent.connect.jdbc.source.TableQuerier.maybeStartQuery(TableQuerier.java:81)
at io.confluent.connect.jdbc.source.TimestampIncrementingTableQuerier.maybeStartQuery(TimestampIncrementingTableQuerier.java:57)
at io.confluent.connect.jdbc.source.JdbcSourceTask.poll(JdbcSourceTask.java:190)
at org.apache.kafka.connect.runtime.WorkerSourceTask.execute(WorkerSourceTask.java:155)
at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:140)
at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:175)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
[2017-04-10 15:06:52,901] INFO Stopping task ci-engine-bbb-3 (org.apache.kafka.connect.runtime.Worker:341)
[2017-04-10 15:06:52,901] INFO Closing the Kafka producer with timeoutMillis = 30000 ms.

This is like a slow poison and eventually all tasks on 1 worker(sometimes the older one or at other times the newly added one) shows this for all the tasks in that worker. Eventually, this leads to tasks on that worker and then that connector itself to be UNASSIGNED.

Regarding the exception above, I have set connectTimeOut parameter in the jdbc url to 5s. It was suggested to us here : https://github.com/confluentinc/kafka-connect-jdbc/issues/160.

Regarding version, kafka version is 0.10.1.0. And confluent version is 3.1.1. Do you think moving to 3.2.2 help us in fixing this issue?

[ewencp]

I can't think of a fix between those versions that would be relevant (but double check the changelog just in case).

The exception MySQLNonTransientConnectionException : No operations allowed after connection closed. looks suspicious -- looks like a connection is being used after it's been closed. Perhaps that is related to the connectTimeOut. If the exception is of a type we can safely catch and retry we could do that, but it's often difficult to tell without digging into driver-specific exception types.

The place it happens is after the prepared statement is created and the query is executed -- it happens only once we are reading off the result set. It's unclear to me how it is getting closed in that period.

The UNASSIGNED state is also odd -- it indicates that the task was shut down cleanly. The exception being logged there is being handled, but when it is handled the processing is supposed to continue.

Any chance you could run with a higher log level, e.g. DEBUG? There are a couple of other log messages that might make it clearer what is going on.

[wicknicks]

@vamossagar12 are you seeing this issue with the newer versions of the Connect framework? The herder, rebalancing logic and rest api are more mature and stable now, and should have dealt with such issues. I'm closing this issue, but if you are seeing similar problems, feel free to reopen it.

[peeyar]

I see this today.. I am using confluent 5.0 . I tired to create an elastic sink using REST API ( also passed user name and password as paramers along with url). I see the worker in RUNNING state. But the task is in UNASSIGNED State.