You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by Franco Giacosa <fg...@gmail.com> on 2016/08/23 14:25:21 UTC
unexpected consumer rebalance 0.9.0.1
Hi I am experiencing the following issue in kafka 0.9.0.1,
I have a consumer, that is in a consumer group alone processing and
commiting the offsets and at one point the group does a rebalance (I don't
know why) and removes the group.
The weird situation is that it seems that the consumer is working as
expected and in less than 1 second between commiting the previous offset,
processing the current message and commiting that offset it fails.
I imagine this has nothing to do with a timeout, but either way we have
those times setup pretty high request.timeout.ms=600000,
group.max.session.timeout.ms=500000
*KAFKA SERVER.LOG have the following lines around that time*
[*2016-08-19 01:09:10,857*] INFO [Group Metadata Manager on Broker 0]:
Removed 0 expired offsets in 0 milliseconds.
(kafka.coordinator.GroupMetadataManager)
[*2016-08-19 01:14:46,082*] INFO [GroupCoordinator 0]: Preparing to
restabilize group error-group with old generation 43
(kafka.coordinator.GroupCoordinator)
[*2016-08-19 01:14:46,083*] INFO [GroupCoordinator 0]: Group error-group
generation 43 is dead and removed (kafka.coordinator.GroupCoordinator)
[*2016-08-19 01:19:10,857*] INFO [Group Metadata Manager on Broker 0]:
Removed 0 expired offsets in 0 milliseconds.
(kafka.coordinator.GroupMetadataManager)
*On the consumer client I can see the following on the log around the same
time *
*01:14:44.839* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator -
Committed offset 132 for partition error-group-topic-4
*01:14:45.258* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator -
Committed offset 133 for partition error-group-topic-4
*01:14:45.703* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator -
Committed offset 134 for partition error-group-topic-4
*01:14:46.139* [pool-5-thread-3] ERROR o.a.k.c.c.i.ConsumerCoordinator -
Error ILLEGAL_GENERATION occurred while committing offsets for group
error-group
*01:14:46.140* [pool-5-thread-3] DEBUG c.g.e.c.f.m.ConnectorHandler -
Consumer Id=error-group : kafka-exception=Commit cannot be completed due to
group rebalance
org.apache.kafka.clients.consumer.CommitFailedException: Commit cannot be
completed due to group rebalance
at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator$OffsetCommitResponseHandler.handle(ConsumerCoordinator.java:552)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator$OffsetCommitResponseHandler.handle(ConsumerCoordinator.java:493)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.AbstractCoordinator$CoordinatorResponseHandler.onSuccess(AbstractCoordinator.java:665)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.AbstractCoordinator$CoordinatorResponseHandler.onSuccess(AbstractCoordinator.java:644)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.RequestFuture$1.onSuccess(RequestFuture.java:167)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.RequestFuture.fireSuccess(RequestFuture.java:133)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.RequestFuture.complete(RequestFuture.java:107)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler.onComplete(ConsumerNetworkClient.java:380)
~[kafka-clients-0.9.0.1.jar:na]
at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:274)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.clientPoll(ConsumerNetworkClient.java:320)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:213)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:193)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:163)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.commitOffsetsSync(ConsumerCoordinator.java:358)
~[kafka-clients-0.9.0.1.jar:na]
at
org.apache.kafka.clients.consumer.KafkaConsumer.commitSync(KafkaConsumer.java:968)
~[kafka-clients-0.9.0.1.jar:na]
RE: unexpected consumer rebalance 0.9.0.1
Posted by "Burtsev, Kirill" <Ki...@cmegroup.com>.
I also have seen this happening. Though, error said that it could be because of commit intervals were greater than configured timeout, it is not the case.
-----Original Message-----
From: Jaikiran Pai [mailto:jai.forums2013@gmail.com]
Sent: Friday, August 26, 2016 8:50 AM
To: users@kafka.apache.org
Subject: Re: unexpected consumer rebalance 0.9.0.1
What's the heartbeat interval that you have set on these consumer configs (if any)? Can you also paste a snippet of your code to show what the consumer code looks like (including the poll and commit calls)?
-Jaikiran
On Tuesday 23 August 2016 07:55 PM, Franco Giacosa wrote:
> Hi I am experiencing the following issue in kafka 0.9.0.1,
>
> I have a consumer, that is in a consumer group alone processing and
> commiting the offsets and at one point the group does a rebalance (I
> don't know why) and removes the group.
>
> The weird situation is that it seems that the consumer is working as
> expected and in less than 1 second between commiting the previous
> offset, processing the current message and commiting that offset it fails.
>
> I imagine this has nothing to do with a timeout, but either way we
> have those times setup pretty high request.timeout.ms=600000,
> group.max.session.timeout.ms=500000
>
>
>
> *KAFKA SERVER.LOG have the following lines around that time*
>
> [*2016-08-19 01:09:10,857*] INFO [Group Metadata Manager on Broker 0]:
> Removed 0 expired offsets in 0 milliseconds.
> (kafka.coordinator.GroupMetadataManager)
> [*2016-08-19 01:14:46,082*] INFO [GroupCoordinator 0]: Preparing to
> restabilize group error-group with old generation 43
> (kafka.coordinator.GroupCoordinator)
> [*2016-08-19 01:14:46,083*] INFO [GroupCoordinator 0]: Group
> error-group generation 43 is dead and removed
> (kafka.coordinator.GroupCoordinator)
> [*2016-08-19 01:19:10,857*] INFO [Group Metadata Manager on Broker 0]:
> Removed 0 expired offsets in 0 milliseconds.
> (kafka.coordinator.GroupMetadataManager)
>
> *On the consumer client I can see the following on the log around the
> same time *
>
> *01:14:44.839* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator
> - Committed offset 132 for partition error-group-topic-4
> *01:14:45.258* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator
> - Committed offset 133 for partition error-group-topic-4
> *01:14:45.703* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator
> - Committed offset 134 for partition error-group-topic-4
> *01:14:46.139* [pool-5-thread-3] ERROR o.a.k.c.c.i.ConsumerCoordinator
> - Error ILLEGAL_GENERATION occurred while committing offsets for group
> error-group
> *01:14:46.140* [pool-5-thread-3] DEBUG c.g.e.c.f.m.ConnectorHandler -
> Consumer Id=error-group : kafka-exception=Commit cannot be completed
> due to group rebalance
> org.apache.kafka.clients.consumer.CommitFailedException: Commit cannot
> be completed due to group rebalance at
> org.apache.kafka.clients.consumer.internals.ConsumerCoordinator$Offset
> CommitResponseHandler.handle(ConsumerCoordinator.java:552)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerCoordinator$Offset
> CommitResponseHandler.handle(ConsumerCoordinator.java:493)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.AbstractCoordinator$Coordi
> natorResponseHandler.onSuccess(AbstractCoordinator.java:665)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.AbstractCoordinator$Coordi
> natorResponseHandler.onSuccess(AbstractCoordinator.java:644)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.RequestFuture$1.onSuccess(
> RequestFuture.java:167)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.RequestFuture.fireSuccess(
> RequestFuture.java:133)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.RequestFuture.complete(Req
> uestFuture.java:107)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$Requ
> estFutureCompletionHandler.onComplete(ConsumerNetworkClient.java:380)
> ~[kafka-clients-0.9.0.1.jar:na]
> at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:274)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.clie
> ntPoll(ConsumerNetworkClient.java:320)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll
> (ConsumerNetworkClient.java:213)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll
> (ConsumerNetworkClient.java:193)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll
> (ConsumerNetworkClient.java:163)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.commit
> OffsetsSync(ConsumerCoordinator.java:358)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.KafkaConsumer.commitSync(KafkaConsum
> er.java:968)
> ~[kafka-clients-0.9.0.1.jar:na]
>
________________________________
NOTICE: This message, and any attachments, are for the intended recipient(s) only, may contain information that is privileged, confidential and/or proprietary and subject to important terms and conditions available at E-Communication Disclaimer<http://www.cmegroup.com/tools-information/communications/e-communication-disclaimer.html>. If you are not the intended recipient, please delete this message. CME Group and its subsidiaries reserve the right to monitor all email communications that occur on CME Group information systems.
Re: unexpected consumer rebalance 0.9.0.1
Posted by Jaikiran Pai <ja...@gmail.com>.
What's the heartbeat interval that you have set on these consumer
configs (if any)? Can you also paste a snippet of your code to show what
the consumer code looks like (including the poll and commit calls)?
-Jaikiran
On Tuesday 23 August 2016 07:55 PM, Franco Giacosa wrote:
> Hi I am experiencing the following issue in kafka 0.9.0.1,
>
> I have a consumer, that is in a consumer group alone processing and
> commiting the offsets and at one point the group does a rebalance (I don't
> know why) and removes the group.
>
> The weird situation is that it seems that the consumer is working as
> expected and in less than 1 second between commiting the previous offset,
> processing the current message and commiting that offset it fails.
>
> I imagine this has nothing to do with a timeout, but either way we have
> those times setup pretty high request.timeout.ms=600000,
> group.max.session.timeout.ms=500000
>
>
>
> *KAFKA SERVER.LOG have the following lines around that time*
>
> [*2016-08-19 01:09:10,857*] INFO [Group Metadata Manager on Broker 0]:
> Removed 0 expired offsets in 0 milliseconds.
> (kafka.coordinator.GroupMetadataManager)
> [*2016-08-19 01:14:46,082*] INFO [GroupCoordinator 0]: Preparing to
> restabilize group error-group with old generation 43
> (kafka.coordinator.GroupCoordinator)
> [*2016-08-19 01:14:46,083*] INFO [GroupCoordinator 0]: Group error-group
> generation 43 is dead and removed (kafka.coordinator.GroupCoordinator)
> [*2016-08-19 01:19:10,857*] INFO [Group Metadata Manager on Broker 0]:
> Removed 0 expired offsets in 0 milliseconds.
> (kafka.coordinator.GroupMetadataManager)
>
> *On the consumer client I can see the following on the log around the same
> time *
>
> *01:14:44.839* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator -
> Committed offset 132 for partition error-group-topic-4
> *01:14:45.258* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator -
> Committed offset 133 for partition error-group-topic-4
> *01:14:45.703* [pool-5-thread-3] DEBUG o.a.k.c.c.i.ConsumerCoordinator -
> Committed offset 134 for partition error-group-topic-4
> *01:14:46.139* [pool-5-thread-3] ERROR o.a.k.c.c.i.ConsumerCoordinator -
> Error ILLEGAL_GENERATION occurred while committing offsets for group
> error-group
> *01:14:46.140* [pool-5-thread-3] DEBUG c.g.e.c.f.m.ConnectorHandler -
> Consumer Id=error-group : kafka-exception=Commit cannot be completed due to
> group rebalance
> org.apache.kafka.clients.consumer.CommitFailedException: Commit cannot be
> completed due to group rebalance
> at
> org.apache.kafka.clients.consumer.internals.ConsumerCoordinator$OffsetCommitResponseHandler.handle(ConsumerCoordinator.java:552)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerCoordinator$OffsetCommitResponseHandler.handle(ConsumerCoordinator.java:493)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.AbstractCoordinator$CoordinatorResponseHandler.onSuccess(AbstractCoordinator.java:665)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.AbstractCoordinator$CoordinatorResponseHandler.onSuccess(AbstractCoordinator.java:644)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.RequestFuture$1.onSuccess(RequestFuture.java:167)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.RequestFuture.fireSuccess(RequestFuture.java:133)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.RequestFuture.complete(RequestFuture.java:107)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient$RequestFutureCompletionHandler.onComplete(ConsumerNetworkClient.java:380)
> ~[kafka-clients-0.9.0.1.jar:na]
> at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:274)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.clientPoll(ConsumerNetworkClient.java:320)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:213)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:193)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:163)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.commitOffsetsSync(ConsumerCoordinator.java:358)
> ~[kafka-clients-0.9.0.1.jar:na]
> at
> org.apache.kafka.clients.consumer.KafkaConsumer.commitSync(KafkaConsumer.java:968)
> ~[kafka-clients-0.9.0.1.jar:na]
>