You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by Kamal C <ka...@gmail.com> on 2016/04/13 06:09:45 UTC
Re: Kafka consumer timing out while connecting to Zookeeper
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 "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
>>