Kafka connect stops when connector with faulty configuration is registered

[Adarsh Lal]

Hi,

I was trying to add a connector to the Kafka connect started in distributed mode. 

I uploaded the jar file into lib folder.

Registered the connector.

But some errors were shown in the log :

[2016-10-12 10:42:04,224] ERROR Failed to reconfigure connector's tasks, retrying after backoff: (org.apache.kafka.connect.runtime.distributed.DistributedHerder:807)
java.lang.NullPointerException
 at org.apache.kafka.common.config.AbstractConfig.<init>(AbstractConfig.java:51)
 at org.apache.kafka.common.config.AbstractConfig.<init>(AbstractConfig.java:62)
 at org.apache.kafka.connect.runtime.ConnectorConfig.<init>(ConnectorConfig.java:79)
 at org.apache.kafka.connect.runtime.SinkConnectorConfig.<init>(SinkConnectorConfig.java:48)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.reconfigureConnector(DistributedHerder.java:842)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.reconfigureConnectorTasksWithRetry(DistributedHerder.java:799)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.access$800(DistributedHerder.java:92)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder$11$1.call(DistributedHerder.java:812)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder$11$1.call(DistributedHerder.java:809)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.tick(DistributedHerder.java:232)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.run(DistributedHerder.java:176)
 at java.lang.Thread.run(Thread.java:745)
[2016-10-12 10:42:04,225] ERROR Unexpected error during connector task reconfiguration:  (org.apache.kafka.connect.runtime.distributed.DistributedHerder:818)
[2016-10-12 10:42:04,225] ERROR Task reconfiguration for cassandra-sink-connector failed unexpectedly, this connector will not be properly reconfigured unless manually triggered. (org.apache.kafka.connect.runtime.distributed.DistributedHerder:819)
[2016-10-12 10:42:04,226] DEBUG Revoking previous assignment Assignment{error=0, leader='connect-1-8b26cffe-f3ef-46b8-b630-23db9384ef02', leaderUrl='http://127.0.1.1:8083/', offset=23301, connectorIds=[cassandra, mqtt], taskIds=[mqtt-0, mqtt-1, mqtt-2]} (org.apache.kafka.connect.runtime.distributed.WorkerCoordinator:235)
[2016-10-12 10:42:04,226] INFO Rebalance started (org.apache.kafka.connect.runtime.distributed.DistributedHerder:1044)
[2016-10-12 10:42:04,233] INFO Stopping connector cassandra (org.apache.kafka.connect.runtime.Worker:278)
[2016-10-12 10:42:04,233] ERROR Uncaught exception in herder work thread, exiting:  (org.apache.kafka.connect.runtime.distributed.DistributedHerder:183)
org.apache.kafka.connect.errors.ConnectException: Connector cassandra not found in this worker.
 at org.apache.kafka.connect.runtime.Worker.stopConnector(Worker.java:282)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder$RebalanceListener.onRevoked(DistributedHerder.java:1057)
 at org.apache.kafka.connect.runtime.distributed.WorkerCoordinator.onJoinPrepare(WorkerCoordinator.java:237)
 at org.apache.kafka.clients.consumer.internals.AbstractCoordinator.ensureActiveGroup(AbstractCoordinator.java:212)
 at org.apache.kafka.connect.runtime.distributed.WorkerGroupMember.ensureActive(WorkerGroupMember.java:135)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.tick(DistributedHerder.java:204)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.run(DistributedHerder.java:176)
 at java.lang.Thread.run(Thread.java:745)

And The connect itself stopped.

[2016-10-12 10:42:04,357] INFO REST server stopped (org.apache.kafka.connect.runtime.rest.RestServer:165)
[2016-10-12 10:42:04,357] INFO Herder stopping (org.apache.kafka.connect.runtime.distributed.DistributedHerder:362)
[2016-10-12 10:42:04,357] INFO Herder stopped (org.apache.kafka.connect.runtime.distributed.DistributedHerder:382)
[2016-10-12 10:42:04,357] INFO Kafka Connect stopped (org.apache.kafka.connect.runtime.Connect:73)

So I removed the jar from /lib and started the connect. I was planning to delete the connector via the REST API. But the connect stopped again. The error in log was 

[2016-10-12 10:50:22,772] ERROR Uncaught exception in herder work thread, exiting:  (org.apache.kafka.connect.runtime.distributed.DistributedHerder:183)
org.apache.kafka.connect.errors.ConnectException: Failed to find any class that implements Connector and which name matches com.tuplejump.kafka.connect.cassandra.CassandraSink available connectors are: org.apache.kafka.connect.source.SourceConnector, org.apache.kafka.connect.file.FileStreamSinkConnector, org.apache.kafka.connect.sink.SinkConnector, org.apache.kafka.connect.tools.MockSinkConnector, com.evokly.kafka.connect.mqtt.MqttSourceConnector, org.apache.kafka.connect.tools.VerifiableSinkConnector, org.apache.kafka.connect.tools.MockConnector, org.apache.kafka.connect.tools.VerifiableSourceConnector, org.apache.kafka.connect.elasticsearchschema.ElasticsearchSinkConnector, org.apache.kafka.connect.file.FileStreamSourceConnector, org.apache.kafka.connect.tools.MockSourceConnector
 at org.apache.kafka.connect.runtime.Worker.getConnectorClass(Worker.java:226)
 at org.apache.kafka.connect.runtime.Worker.startConnector(Worker.java:166)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.startConnector(DistributedHerder.java:789)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.startWork(DistributedHerder.java:755)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.handleRebalanceCompleted(DistributedHerder.java:715)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.tick(DistributedHerder.java:206)
 at org.apache.kafka.connect.runtime.distributed.DistributedHerder.run(DistributedHerder.java:176)
 at java.lang.Thread.run(Thread.java:745)
[2016-10-12 10:50:22,773] INFO Kafka Connect stopping (org.apache.kafka.connect.runtime.Connect:68)
[2016-10-12 10:50:22,773] INFO Stopping REST server (org.apache.kafka.connect.runtime.rest.RestServer:154)
[2016-10-12 10:50:22,773] DEBUG stopping org.eclipse.jetty.server.Server@3dfc5fb8 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,776] DEBUG Graceful shutdown org.eclipse.jetty.server.Server@3dfc5fb8 by  (org.eclipse.jetty.server.Server:418)
[2016-10-12 10:50:22,776] DEBUG stopping ServerConnector@6121c9d6{HTTP/1.1}{0.0.0.0:8083} (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,776] DEBUG stopping org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@612679d6 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,777] DEBUG stopping org.eclipse.jetty.io.SelectorManager$ManagedSelector@6e6d5d29 keys=0 selected=0 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,777] DEBUG Stopping org.eclipse.jetty.io.SelectorManager$ManagedSelector@6e6d5d29 keys=0 selected=0 (org.eclipse.jetty.io.SelectorManager:432)
[2016-10-12 10:50:22,777] DEBUG Queued change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Stop@5e6a799f (org.eclipse.jetty.io.SelectorManager:480)
[2016-10-12 10:50:22,778] DEBUG Selector loop woken up from select, 0/0 selected (org.eclipse.jetty.io.SelectorManager:602)
[2016-10-12 10:50:22,778] DEBUG Running change org.eclipse.jetty.io.SelectorManager$ManagedSelector$Stop@5e6a799f (org.eclipse.jetty.io.SelectorManager:525)
[2016-10-12 10:50:22,788] DEBUG Stopped org.eclipse.jetty.io.SelectorManager$ManagedSelector@6e6d5d29 keys=-1 selected=-1 (org.eclipse.jetty.io.SelectorManager:437)
[2016-10-12 10:50:22,789] DEBUG STOPPED org.eclipse.jetty.io.SelectorManager$ManagedSelector@6e6d5d29 keys=-1 selected=-1 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,790] DEBUG STOPPED org.eclipse.jetty.server.ServerConnector$ServerConnectorManager@612679d6 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,790] DEBUG stopping HttpConnectionFactory@5ed828d{HTTP/1.1} (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,790] DEBUG STOPPED HttpConnectionFactory@5ed828d{HTTP/1.1} (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,790] DEBUG stopping org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@a38d7a3 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,790] DEBUG STOPPED org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@a38d7a3 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,790] INFO Stopped ServerConnector@6121c9d6{HTTP/1.1}{0.0.0.0:8083} (org.eclipse.jetty.server.ServerConnector:306)
[2016-10-12 10:50:22,791] DEBUG STOPPED ServerConnector@6121c9d6{HTTP/1.1}{0.0.0.0:8083} (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,791] DEBUG stopping org.eclipse.jetty.server.Server@3dfc5fb8 (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,791] DEBUG stopping org.eclipse.jetty.server.session.HashSessionIdManager@56cdfb3b (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,791] DEBUG STOPPED org.eclipse.jetty.server.session.HashSessionIdManager@56cdfb3b (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,791] DEBUG stopping org.eclipse.jetty.server.handler.StatisticsHandler@10feca44 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,791] DEBUG stopping org.eclipse.jetty.server.handler.StatisticsHandler@10feca44 (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,791] DEBUG stopping org.eclipse.jetty.server.handler.HandlerCollection@50b5ac82[o.e.j.s.ServletContextHandler@29e495ff{/,null,SHUTDOWN}, org.eclipse.jetty.server.handler.DefaultHandler@101952da, org.eclipse.jetty.server.handler.RequestLogHandler@1cbb87f3] (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,791] DEBUG stopping org.eclipse.jetty.server.handler.HandlerCollection@50b5ac82[o.e.j.s.ServletContextHandler@29e495ff{/,null,SHUTDOWN}, org.eclipse.jetty.server.handler.DefaultHandler@101952da, org.eclipse.jetty.server.handler.RequestLogHandler@1cbb87f3] (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,792] DEBUG stopping org.eclipse.jetty.server.handler.RequestLogHandler@1cbb87f3 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,792] DEBUG stopping org.eclipse.jetty.server.handler.RequestLogHandler@1cbb87f3 (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,792] DEBUG stopping org.eclipse.jetty.server.Slf4jRequestLog@1a4013 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,792] DEBUG STOPPED org.eclipse.jetty.server.Slf4jRequestLog@1a4013 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,791] DEBUG  (org.eclipse.jetty.util.thread.ShutdownThread:150)
java.lang.IllegalStateException: !STOPPED
 at org.eclipse.jetty.server.handler.HandlerWrapper.destroy(HandlerWrapper.java:131)
 at org.eclipse.jetty.util.thread.ShutdownThread.run(ShutdownThread.java:144)
[2016-10-12 10:50:22,791] DEBUG Stopped Thread[qtp1392425346-17-selector-ServerConnectorManager@612679d6/0,5,main] on org.eclipse.jetty.io.SelectorManager$ManagedSelector@6e6d5d29 keys=-1 selected=-1 (org.eclipse.jetty.io.SelectorManager:556)
[2016-10-12 10:50:22,793] DEBUG STOPPED org.eclipse.jetty.server.handler.RequestLogHandler@1cbb87f3 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,793] DEBUG stopping org.eclipse.jetty.server.handler.DefaultHandler@101952da (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,793] DEBUG stopping org.eclipse.jetty.server.handler.DefaultHandler@101952da (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,793] DEBUG STOPPED org.eclipse.jetty.server.handler.DefaultHandler@101952da (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,793] DEBUG stopping o.e.j.s.ServletContextHandler@29e495ff{/,null,SHUTDOWN} (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,793] DEBUG stopping o.e.j.s.ServletContextHandler@29e495ff{/,null,UNAVAILABLE} (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,793] DEBUG stopping org.eclipse.jetty.server.session.SessionHandler@2bfc268b (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,793] DEBUG stopping org.eclipse.jetty.server.session.SessionHandler@2bfc268b (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,793] DEBUG stopping org.eclipse.jetty.servlet.ServletHandler@625732 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,794] DEBUG stopping org.eclipse.jetty.servlet.ServletHandler@625732 (org.eclipse.jetty.server.handler.AbstractHandler:72)
[2016-10-12 10:50:22,794] DEBUG stopping org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-2f217633@12fdc946==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet,-1,false (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,795] DEBUG STOPPED org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-2f217633@12fdc946==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet,-1,false (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,795] DEBUG stopping org.glassfish.jersey.servlet.ServletContainer-2e1d27ba@5b00ead8==org.glassfish.jersey.servlet.ServletContainer,-1,true (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,801] DEBUG STOPPED org.glassfish.jersey.servlet.ServletContainer-2e1d27ba@5b00ead8==org.glassfish.jersey.servlet.ServletContainer,-1,true (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,803] DEBUG STOPPED org.eclipse.jetty.servlet.ServletHandler@625732 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,803] DEBUG stopping org.eclipse.jetty.server.session.HashSessionManager@2f8dad04 (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,803] DEBUG stopping org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@28f2a10f (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,803] DEBUG STOPPED org.eclipse.jetty.util.thread.ScheduledExecutorScheduler@28f2a10f (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,804] DEBUG STOPPED org.eclipse.jetty.server.session.HashSessionManager@2f8dad04 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,804] DEBUG STOPPED org.eclipse.jetty.server.session.SessionHandler@2bfc268b (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,804] INFO Stopped o.e.j.s.ServletContextHandler@29e495ff{/,null,UNAVAILABLE} (org.eclipse.jetty.server.handler.ContextHandler:865)
[2016-10-12 10:50:22,804] DEBUG STOPPED o.e.j.s.ServletContextHandler@29e495ff{/,null,UNAVAILABLE} (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,804] DEBUG STOPPED org.eclipse.jetty.server.handler.HandlerCollection@50b5ac82[o.e.j.s.ServletContextHandler@29e495ff{/,null,UNAVAILABLE}, org.eclipse.jetty.server.handler.DefaultHandler@101952da, org.eclipse.jetty.server.handler.RequestLogHandler@1cbb87f3] (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,804] DEBUG STOPPED org.eclipse.jetty.server.handler.StatisticsHandler@10feca44 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,804] DEBUG stopping qtp1392425346{STARTED,8<=8<=200,i=8,q=0} (org.eclipse.jetty.util.component.AbstractLifeCycle:194)
[2016-10-12 10:50:22,808] DEBUG STOPPED qtp1392425346{STOPPED,8<=8<=200,i=0,q=0} (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,808] DEBUG shutdown already commenced (org.eclipse.jetty.util.thread.ShutdownThread:83)
[2016-10-12 10:50:22,808] DEBUG STOPPED org.eclipse.jetty.server.Server@3dfc5fb8 (org.eclipse.jetty.util.component.AbstractLifeCycle:204)
[2016-10-12 10:50:22,808] DEBUG o.e.j.s.ServletContextHandler@29e495ff{/,null,UNAVAILABLE} added {org.eclipse.jetty.server.session.SessionHandler@2bfc268b,AUTO} (org.eclipse.jetty.util.component.ContainerLifeCycle:324)
[2016-10-12 10:50:22,808] INFO REST server stopped (org.apache.kafka.connect.runtime.rest.RestServer:165)
[2016-10-12 10:50:22,809] INFO Herder stopping (org.apache.kafka.connect.runtime.distributed.DistributedHerder:362)
[2016-10-12 10:50:22,809] INFO Herder stopped (org.apache.kafka.connect.runtime.distributed.DistributedHerder:382)
[2016-10-12 10:50:22,809] INFO Kafka Connect stopped (org.apache.kafka.connect.runtime.Connect:73)

Can somebody suggest a solution.

Thanks in advance.

[Shikhar Bhushan]

Hi Adarsh,

This bug has been fixed here: https://issues.apache.org/jira/browse/KAFKA-4042

The fix will be in the upcoming releases Kafka 0.10.1 and Confluent Platform 3.1.

Best,

Shikhar