[
https://issues.apache.org/jira/browse/KAFKA-3296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15172416#comment-15172416
]
Jason Gustafson commented on KAFKA-3296:
----------------------------------------
[~thecoop1984] Thanks for the logs. Is there only one broker in the cluster?
Also, is there any chance you could enable DEBUG logging for the controller?
What I see is the controller resigning about two minutes after startup and then
there's nothing else in the controller logs. That means either that another
broker took over as the controller, or somehow we've missed an expected event
for the broker to become controller again. I know there have been several JIRAs
tracking failures to receive some Zookeeper events, so we might be hitting one
of those cases. Can you describe how you run Zookeeper in this test? Anyway,
the controller being down explains why the consumer cannot find the group
coordinator.
> 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: 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)
