You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by "Mhaskar, Tushar" <tm...@paypal.com.INVALID> on 2016/04/13 00:09:33 UTC
Kafka consumer timing out while connecting to Zookeeper
Hi ,
I have a 8 node Kafka broker(0.9) with 5 zookeeper machines.
Kafka consumer (0.8.2.1) is not able to connect to zookeeper. I am able to telnet to the machine on port 2181 where the zookeeper is running.
Output of nc
nc -zv 10.196.196.63 2181
Connection to 10.196.196.63 2181 port [tcp/eforward] succeeded!
Excerpt of consumer log:
2016-04-11 09:09:01 ClientCnxn [INFO] Opening socket connection to server 10.196.196.61/10.196.196.61:2181. Will not attempt to authenticate using SASL (unknown error)
2016-04-11 09:09:01 ClientCnxn [INFO] Socket connection established to 10.196.196.61/10.196.196.61:2181, initiating session
2016-04-11 09:09:01 ClientCnxn [INFO] Session establishment complete on server 10.196.196.61/10.196.196.61:2181, sessionid = 0x5352b8a22c002b, negotiated timeout = 4000
2016-04-11 09:09:01 ZkClient [INFO] zookeeper state changed (SyncConnected)
2016-04-11 09:09:04 ClientCnxn [INFO] Client session timed out, have not heard from server in 2667ms for sessionid 0x5352b8a22c002b, closing socket connection and attempting reconnect
2016-04-11 09:09:04 ZkClient [INFO] zookeeper state changed (Disconnected)
2016-04-11 09:09:05 ClientCnxn [INFO] Opening socket connection to server 10.196.196.63/10.196.196.63:2181. Will not attempt to authenticate using SASL (unknown error)
2016-04-11 09:09:05 ClientCnxn [INFO] Socket connection established to 10.196.196.63/10.196.196.63:2181, initiating session
2016-04-11 09:09:05 ClientCnxn [INFO] Session establishment complete on server 10.196.196.63/10.196.196.63:2181, sessionid = 0x5352b8a22c002b, negotiated timeout = 4000
2016-04-11 09:09:05 ZkClient [INFO] zookeeper state changed (SyncConnected)
2016-04-11 09:09:07 ClientCnxn [INFO] Client session timed out, have not heard from server in 2668ms for sessionid 0x5352b8a22c002b, closing socket connection and attempting reconnect
2016-04-11 09:09:07 ZkClient [INFO] zookeeper state changed (Disconnected)
Even after using Kafka consumer (0.9) it is unable to connect to broker.
Excerpt from the consumer log for your reference:
2016-04-12 08:48:51 NetworkClient [DEBUG] Initialize connection to node 1 for sending metadata request
2016-04-12 08:48:51 NetworkClient [DEBUG] Initiating connection to node 1 at 10.196.196.63:9092.
2016-04-12 08:48:51 NetworkClient [DEBUG] Completed connection to node 1
2016-04-12 08:48:51 NetworkClient [DEBUG] Sending metadata request ClientRequest(expectResponse=true, callback=null, request=RequestSend(header={api_key=3,api_version=0,correlation_id=22,client_id=consumer-1}, body={topics=[fpti.platform.enrch]}), isInitiatedByNetworkClient, createdTimeMs=1460476131467, sendTimeMs=0) to node 1
2016-04-12 08:48:51 AbstractCoordinator [DEBUG] Issuing group metadata request to broker 1
2016-04-12 08:49:31 NetworkClient [DEBUG] Disconnecting from node 1 due to request timeout.
2016-04-12 08:49:31 NetworkClient [TRACE] Cancelled request ClientRequest(expectResponse=true, callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@183a37d9, request=RequestSend(header={api_key=10,api_version=0,correlation_id=23,client_id=consumer-1}, body={group_id=paz-3-fpti-enrch-metric-consumer}), createdTimeMs=1460476131477, sendTimeMs=1460476131477) due to node 1 being disconnected
2016-04-12 08:49:31 AbstractCoordinator [DEBUG] Group metadata response ClientResponse(receivedTimeMs=1460476171518, disconnected=true, request=ClientRequest(expectResponse=true, callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@183a37d9, request=RequestSend(header={api_key=10,api_version=0,correlation_id=23,client_id=consumer-1}, body={group_id=paz-3-fpti-enrch-metric-consumer}), createdTimeMs=1460476131477, sendTimeMs=1460476131477), responseBody=null)
Let me know if I am missing on anything.
Thanks
Tushar
Re: Kafka consumer timing out while connecting to Zookeeper
Posted by "Mhaskar, Tushar" <tm...@paypal.com.INVALID>.
Kamal,
GC is fine. I am able to connect to the zk from other machines.
Also, from this consumer machine I am able to connect to another zk for some other cluster.
So machine problem is somewhat ruled out.
Thanks
Tushar
On 4/12/16, 9:09 PM, "Kamal C" <ka...@gmail.com> wrote:
>Tushar,
>
>The issue may happen when GC in Kafka Server takes much time than the
>configured session interval.
>
>Check your GC logs at that time interval.
>
>--Kamal
>On 13-Apr-2016 3:39 AM, "Mhaskar, Tushar" <tm...@paypal.com.invalid>
>wrote:
>
>> Hi ,
>>
>> I have a 8 node Kafka broker(0.9) with 5 zookeeper machines.
>>
>> Kafka consumer (0.8.2.1) is not able to connect to zookeeper. I am able to
>> telnet to the machine on port 2181 where the zookeeper is running.
>>
>> Output of nc
>> nc -zv 10.196.196.63 2181
>> Connection to 10.196.196.63 2181 port [tcp/eforward] succeeded!
>>
>> Excerpt of consumer log:
>> 2016-04-11 09:09:01 ClientCnxn [INFO] Opening socket connection to server
>> 10.196.196.61/10.196.196.61:2181. Will not attempt to authenticate using
>> SASL (unknown error)
>> 2016-04-11 09:09:01 ClientCnxn [INFO] Socket connection established to
>> 10.196.196.61/10.196.196.61:2181, initiating session
>> 2016-04-11 09:09:01 ClientCnxn [INFO] Session establishment complete on
>> server 10.196.196.61/10.196.196.61:2181, sessionid = 0x5352b8a22c002b,
>> negotiated timeout = 4000
>> 2016-04-11 09:09:01 ZkClient [INFO] zookeeper state changed (SyncConnected)
>> 2016-04-11 09:09:04 ClientCnxn [INFO] Client session timed out, have not
>> heard from server in 2667ms for sessionid 0x5352b8a22c002b, closing socket
>> connection and attempting reconnect
>> 2016-04-11 09:09:04 ZkClient [INFO] zookeeper state changed (Disconnected)
>> 2016-04-11 09:09:05 ClientCnxn [INFO] Opening socket connection to server
>> 10.196.196.63/10.196.196.63:2181. Will not attempt to authenticate using
>> SASL (unknown error)
>> 2016-04-11 09:09:05 ClientCnxn [INFO] Socket connection established to
>> 10.196.196.63/10.196.196.63:2181, initiating session
>> 2016-04-11 09:09:05 ClientCnxn [INFO] Session establishment complete on
>> server 10.196.196.63/10.196.196.63:2181, sessionid = 0x5352b8a22c002b,
>> negotiated timeout = 4000
>> 2016-04-11 09:09:05 ZkClient [INFO] zookeeper state changed (SyncConnected)
>> 2016-04-11 09:09:07 ClientCnxn [INFO] Client session timed out, have not
>> heard from server in 2668ms for sessionid 0x5352b8a22c002b, closing socket
>> connection and attempting reconnect
>> 2016-04-11 09:09:07 ZkClient [INFO] zookeeper state changed (Disconnected)
>>
>>
>> Even after using Kafka consumer (0.9) it is unable to connect to broker.
>>
>> Excerpt from the consumer log for your reference:
>> 2016-04-12 08:48:51 NetworkClient [DEBUG] Initialize connection to node 1
>> for sending metadata request
>> 2016-04-12 08:48:51 NetworkClient [DEBUG] Initiating connection to node 1
>> at 10.196.196.63:9092.
>> 2016-04-12 08:48:51 NetworkClient [DEBUG] Completed connection to node 1
>> 2016-04-12 08:48:51 NetworkClient [DEBUG] Sending metadata request
>> ClientRequest(expectResponse=true, callback=null,
>> request=RequestSend(header={api_key=3,api_version=0,correlation_id=22,client_id=consumer-1},
>> body={topics=[fpti.platform.enrch]}), isInitiatedByNetworkClient,
>> createdTimeMs=1460476131467, sendTimeMs=0) to node 1
>> 2016-04-12 08:48:51 AbstractCoordinator [DEBUG] Issuing group metadata
>> request to broker 1
>> 2016-04-12 08:49:31 NetworkClient [DEBUG] Disconnecting from node 1 due to
>> request timeout.
>> 2016-04-12 08:49:31 NetworkClient [TRACE] Cancelled request
>> ClientRequest(expectResponse=true,
>> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@183a37d9,
>> request=RequestSend(header={api_key=10,api_version=0,correlation_id=23,client_id=consumer-1},
>> body={group_id=paz-3-fpti-enrch-metric-consumer}),
>> createdTimeMs=1460476131477, sendTimeMs=1460476131477) due to node 1 being
>> disconnected
>> 2016-04-12 08:49:31 AbstractCoordinator [DEBUG] Group metadata response
>> ClientResponse(receivedTimeMs=1460476171518, disconnected=true,
>> request=ClientRequest(expectResponse=true,
>> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@183a37d9,
>> request=RequestSend(header={api_key=10,api_version=0,correlation_id=23,client_id=consumer-1},
>> body={group_id=paz-3-fpti-enrch-metric-consumer}),
>> createdTimeMs=1460476131477, sendTimeMs=1460476131477), responseBody=null)
>>
>> Let me know if I am missing on anything.
>>
>> Thanks
>> Tushar
>>
Re: Kafka consumer timing out while connecting to Zookeeper
Posted by Kamal C <ka...@gmail.com>.
Tushar,
The issue may happen when GC in Kafka Server takes much time than the
configured session interval.
Check your GC logs at that time interval.
--Kamal
On 13-Apr-2016 3:39 AM, "Mhaskar, Tushar" <tm...@paypal.com.invalid>
wrote:
> Hi ,
>
> I have a 8 node Kafka broker(0.9) with 5 zookeeper machines.
>
> Kafka consumer (0.8.2.1) is not able to connect to zookeeper. I am able to
> telnet to the machine on port 2181 where the zookeeper is running.
>
> Output of nc
> nc -zv 10.196.196.63 2181
> Connection to 10.196.196.63 2181 port [tcp/eforward] succeeded!
>
> Excerpt of consumer log:
> 2016-04-11 09:09:01 ClientCnxn [INFO] Opening socket connection to server
> 10.196.196.61/10.196.196.61:2181. Will not attempt to authenticate using
> SASL (unknown error)
> 2016-04-11 09:09:01 ClientCnxn [INFO] Socket connection established to
> 10.196.196.61/10.196.196.61:2181, initiating session
> 2016-04-11 09:09:01 ClientCnxn [INFO] Session establishment complete on
> server 10.196.196.61/10.196.196.61:2181, sessionid = 0x5352b8a22c002b,
> negotiated timeout = 4000
> 2016-04-11 09:09:01 ZkClient [INFO] zookeeper state changed (SyncConnected)
> 2016-04-11 09:09:04 ClientCnxn [INFO] Client session timed out, have not
> heard from server in 2667ms for sessionid 0x5352b8a22c002b, closing socket
> connection and attempting reconnect
> 2016-04-11 09:09:04 ZkClient [INFO] zookeeper state changed (Disconnected)
> 2016-04-11 09:09:05 ClientCnxn [INFO] Opening socket connection to server
> 10.196.196.63/10.196.196.63:2181. Will not attempt to authenticate using
> SASL (unknown error)
> 2016-04-11 09:09:05 ClientCnxn [INFO] Socket connection established to
> 10.196.196.63/10.196.196.63:2181, initiating session
> 2016-04-11 09:09:05 ClientCnxn [INFO] Session establishment complete on
> server 10.196.196.63/10.196.196.63:2181, sessionid = 0x5352b8a22c002b,
> negotiated timeout = 4000
> 2016-04-11 09:09:05 ZkClient [INFO] zookeeper state changed (SyncConnected)
> 2016-04-11 09:09:07 ClientCnxn [INFO] Client session timed out, have not
> heard from server in 2668ms for sessionid 0x5352b8a22c002b, closing socket
> connection and attempting reconnect
> 2016-04-11 09:09:07 ZkClient [INFO] zookeeper state changed (Disconnected)
>
>
> Even after using Kafka consumer (0.9) it is unable to connect to broker.
>
> Excerpt from the consumer log for your reference:
> 2016-04-12 08:48:51 NetworkClient [DEBUG] Initialize connection to node 1
> for sending metadata request
> 2016-04-12 08:48:51 NetworkClient [DEBUG] Initiating connection to node 1
> at 10.196.196.63:9092.
> 2016-04-12 08:48:51 NetworkClient [DEBUG] Completed connection to node 1
> 2016-04-12 08:48:51 NetworkClient [DEBUG] Sending metadata request
> ClientRequest(expectResponse=true, callback=null,
> request=RequestSend(header={api_key=3,api_version=0,correlation_id=22,client_id=consumer-1},
> body={topics=[fpti.platform.enrch]}), isInitiatedByNetworkClient,
> createdTimeMs=1460476131467, sendTimeMs=0) to node 1
> 2016-04-12 08:48:51 AbstractCoordinator [DEBUG] Issuing group metadata
> request to broker 1
> 2016-04-12 08:49:31 NetworkClient [DEBUG] Disconnecting from node 1 due to
> request timeout.
> 2016-04-12 08:49:31 NetworkClient [TRACE] Cancelled request
> ClientRequest(expectResponse=true,
> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@183a37d9,
> request=RequestSend(header={api_key=10,api_version=0,correlation_id=23,client_id=consumer-1},
> body={group_id=paz-3-fpti-enrch-metric-consumer}),
> createdTimeMs=1460476131477, sendTimeMs=1460476131477) due to node 1 being
> disconnected
> 2016-04-12 08:49:31 AbstractCoordinator [DEBUG] Group metadata response
> ClientResponse(receivedTimeMs=1460476171518, disconnected=true,
> request=ClientRequest(expectResponse=true,
> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@183a37d9,
> request=RequestSend(header={api_key=10,api_version=0,correlation_id=23,client_id=consumer-1},
> body={group_id=paz-3-fpti-enrch-metric-consumer}),
> createdTimeMs=1460476131477, sendTimeMs=1460476131477), responseBody=null)
>
> Let me know if I am missing on anything.
>
> Thanks
> Tushar
>