[ 
https://issues.apache.org/jira/browse/KAFKA-3296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15187284#comment-15187284
 ] 

Simon Cooper commented on KAFKA-3296:
-------------------------------------

Are the logs useful?

We've also started seeing a (possibly unrelated) issue - a new kafka install 
doesn't work, putting this in the logs:

{code}2016-03-09T15:43:22,998 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:delete cxid:0x93 zxid:0x579 
txntype:-1 reqpath:n/a Error Path:/kafkasite1/admin/preferred_replica_election 
Error:KeeperErrorCode = NoNode for /kafkasite1/admin/preferred_replica_election
2016-03-09T15:43:23,142 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0x9a zxid:0x57a 
txntype:-1 reqpath:n/a Error Path:/kafkasite1/brokers Error:KeeperErrorCode = 
NodeExists for /kafkasite1/brokers
2016-03-09T15:43:23,142 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0x9b zxid:0x57b 
txntype:-1 reqpath:n/a Error Path:/kafkasite1/brokers/ids Error:KeeperErrorCode 
= NodeExists for /kafkasite1/brokers/ids
2016-03-09T15:43:23,309 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xa2 zxid:0x57d 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions/19 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions/19
2016-03-09T15:43:23,313 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xa3 zxid:0x57e 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions
2016-03-09T15:43:23,325 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xa7 zxid:0x582 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions/30 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions/30
2016-03-09T15:43:23,341 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xaa zxid:0x585 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions/47 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions/47
2016-03-09T15:43:23,349 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xad zxid:0x588 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions/29 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions/29
2016-03-09T15:43:23,357 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xb1 zxid:0x58b 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions/41 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions/41
2016-03-09T15:43:23,367 | INFO | o.a.z.s.PrepRequestProcessor 
[ProcessThread(sid:0 cport:-1):] | Got user-level KeeperException when 
processing sessionid:0x1535bf80f4e004a type:create cxid:0xba zxid:0x58e 
txntype:-1 reqpath:n/a Error 
Path:/kafkasite1/brokers/topics/__consumer_offsets/partitions/39 
Error:KeeperErrorCode = NoNode for 
/kafkasite1/brokers/topics/__consumer_offsets/partitions/39{code}

Any client connection can't get topic metadata until both zookeeper and kafka 
are restarted

> All consumer reads hang indefinately
> ------------------------------------
>
>                 Key: KAFKA-3296
>                 URL: https://issues.apache.org/jira/browse/KAFKA-3296
>             Project: Kafka
>          Issue Type: Bug
>    Affects Versions: 0.9.0.0, 0.9.0.1
>            Reporter: Simon Cooper
>            Priority: Critical
>         Attachments: controller.zip, kafkalogs.zip
>
>
> We've got several integration tests that bring up systems on VMs for testing. 
> We've recently upgraded to 0.9, and very occasionally we occasionally see an 
> issue where every consumer that tries to read from the broker hangs, spamming 
> the following in their logs:
> {code}2016-02-26T12:25:37,856 | DEBUG | o.a.k.c.NetworkClient 
> [pool-10-thread-1] | Sending metadata request 
> ClientRequest(expectResponse=true, callback=null, 
> request=RequestSend(header={api_key=3,api_version=0,correlation_id=21905,client_id=consumer-1},
>  body={topics=[Topic1]}), isInitiatedByNetworkClient, 
> createdTimeMs=1456489537856, sendTimeMs=0) to node 1
> 2016-02-26T12:25:37,856 | DEBUG | o.a.k.c.Metadata [pool-10-thread-1] | 
> Updated cluster metadata version 10954 to Cluster(nodes = [Node(1, 
> server.internal, 9092)], partitions = [Partition(topic = Topic1, partition = 
> 0, leader = 1, replicas = [1,], isr = [1,]])
> 2016-02-26T12:25:37,856 | DEBUG | o.a.k.c.c.i.AbstractCoordinator 
> [pool-10-thread-1] | Issuing group metadata request to broker 1
> 2016-02-26T12:25:37,857 | DEBUG | o.a.k.c.c.i.AbstractCoordinator 
> [pool-10-thread-1] | Group metadata response 
> ClientResponse(receivedTimeMs=1456489537857, disconnected=false, 
> request=ClientRequest(expectResponse=true, 
> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@28edb273,
>  
> request=RequestSend(header={api_key=10,api_version=0,correlation_id=21906,client_id=consumer-1},
>  body={group_id=}), createdTimeMs=1456489537856, sendTimeMs=1456489537856), 
> responseBody={error_code=15,coordinator={node_id=-1,host=,port=-1}})
> 2016-02-26T12:25:37,956 | DEBUG | o.a.k.c.NetworkClient [pool-10-thread-1] | 
> Sending metadata request ClientRequest(expectResponse=true, callback=null, 
> request=RequestSend(header={api_key=3,api_version=0,correlation_id=21907,client_id=consumer-1},
>  body={topics=[Topic1]}), isInitiatedByNetworkClient, 
> createdTimeMs=1456489537956, sendTimeMs=0) to node 1
> 2016-02-26T12:25:37,956 | DEBUG | o.a.k.c.Metadata [pool-10-thread-1] | 
> Updated cluster metadata version 10955 to Cluster(nodes = [Node(1, 
> server.internal, 9092)], partitions = [Partition(topic = Topic1, partition = 
> 0, leader = 1, replicas = [1,], isr = [1,]])
> 2016-02-26T12:25:37,956 | DEBUG | o.a.k.c.c.i.AbstractCoordinator 
> [pool-10-thread-1] | Issuing group metadata request to broker 1
> 2016-02-26T12:25:37,957 | DEBUG | o.a.k.c.c.i.AbstractCoordinator 
> [pool-10-thread-1] | Group metadata response 
> ClientResponse(receivedTimeMs=1456489537957, disconnected=false, 
> request=ClientRequest(expectResponse=true, 
> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@40cee8cc,
>  
> request=RequestSend(header={api_key=10,api_version=0,correlation_id=21908,client_id=consumer-1},
>  body={group_id=}), createdTimeMs=1456489537956, sendTimeMs=1456489537956), 
> responseBody={error_code=15,coordinator={node_id=-1,host=,port=-1}})
> 2016-02-26T12:25:38,056 | DEBUG | o.a.k.c.NetworkClient [pool-10-thread-1] | 
> Sending metadata request ClientRequest(expectResponse=true, callback=null, 
> request=RequestSend(header={api_key=3,api_version=0,correlation_id=21909,client_id=consumer-1},
>  body={topics=[Topic1]}), isInitiatedByNetworkClient, 
> createdTimeMs=1456489538056, sendTimeMs=0) to node 1
> 2016-02-26T12:25:38,056 | DEBUG | o.a.k.c.Metadata [pool-10-thread-1] | 
> Updated cluster metadata version 10956 to Cluster(nodes = [Node(1, 
> server.internal, 9092)], partitions = [Partition(topic = Topic1, partition = 
> 0, leader = 1, replicas = [1,], isr = [1,]])
> 2016-02-26T12:25:38,056 | DEBUG | o.a.k.c.c.i.AbstractCoordinator 
> [pool-10-thread-1] | Issuing group metadata request to broker 1
> 2016-02-26T12:25:38,057 | DEBUG | o.a.k.c.c.i.AbstractCoordinator 
> [pool-10-thread-1] | Group metadata response 
> ClientResponse(receivedTimeMs=1456489538057, disconnected=false, 
> request=ClientRequest(expectResponse=true, 
> callback=org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler@439e25fb,
>  
> request=RequestSend(header={api_key=10,api_version=0,correlation_id=21910,client_id=consumer-1},
>  body={group_id=}), createdTimeMs=1456489538056, sendTimeMs=1456489538056), 
> responseBody={error_code=15,coordinator={node_id=-1,host=,port=-1}}){code}
> This persists for any 0.9 consumer trying to read from the topic (we haven't 
> confirmed if this is for a single topic or for any topic on the broker). 0.8 
> consumers can read from the broker without issues. This is fixed by a broker 
> restart.
> This was observed on a single-broker cluster. There were no suspicious log 
> messages on the server.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to