We have attached more logs where the fetchers are stopped.
https://issues.apache.org/jira/browse/KAFKA-693 issue mentions about this
issue, and do we need to upgrade to 0.8.0 release for this fix?
Regards,
RJ
-----Original Message-----
From: Seshadri, Balaji
Sent: Saturday, January 11, 2014 3:34 PM
To: users@kafka.apache.org
Cc: Gulia, Vikram; Nanjegowda, Mithunraj; Behera, Ajit; Withers, Robert;
ShankenpurMayanna, Diwakar
Subject: RE: Looks like consumer fetchers get stopped we are not getting any
data
We found the below bug in Kafka JIRA.
https://issues.apache.org/jira/browse/KAFKA-693
Could you guys please let us know if this bug is causing the fetchers getting
stooped because of rebalance failure,we are using 0.8-beta and this fix seems
to be in 0.8 version.
The issue happens only when we run it in tomcat,when we use JUnits with same
group.id to test we receive the messages.It would be great if you could help us
confirm if it is a bug.
Also we would like to know if we need to upgrade the server/client to 0.8 or
just server side code.
________________________________________
From: Rob Withers [robert.w.with...@gmail.com]
Sent: Friday, January 10, 2014 10:17 PM
To: users@kafka.apache.org
Subject: Re: Looks like consumer fetchers get stopped we are not getting any
data
That was an interesting section too. Which GC settings would you suggest?
Thank you,
- charlie
> On Jan 10, 2014, at 10:11 PM, Jun Rao <jun...@gmail.com> wrote:
>
> Have you looked at our FAQ, especially
> https://cwiki.apache.org/confluence/display/KAFKA/FAQ#FAQ-Whyaretheremanyrebalancesinmyconsumerlog
> ?
>
> Thanks,
>
> Jun
>
>
> On Fri, Jan 10, 2014 at 2:25 PM, Seshadri, Balaji
> <balaji.sesha...@dish.com>wrote:
>
>> Any clue would be helpful.
>>
>> -----Original Message-----
>> From: Seshadri, Balaji [mailto:balaji.sesha...@dish.com]
>> Sent: Friday, January 10, 2014 12:46 PM
>> To: users@kafka.apache.org
>> Subject: RE: Looks like consumer fetchers get stopped we are not getting
>> any data
>>
>> Yes rebalance begins and exceptions occurs.
>>
>>
>> {2014-01-10 00:58:11,293} INFO
>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad59660b_watcher_executor]
>> (?:?) - [account-i
>> nfo-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad59660b], Cleared the
>> data chunks in all the consumer message iterators
>> {2014-01-10 00:58:11,293} INFO
>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad59660b_watcher_executor]
>> (?:?) - [account-i
>> nfo-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad59660b], Committing
>> all offsets after clearing the fetcher queues
>> {2014-01-10 00:58:11,298} DEBUG [catalina-exec-12-SendThread(
>> tvip-m1-mw-zookeeper.dish.com:2181)] (ClientCnxn.java:759) - Got ping
>> response for sessionid: 0x1437b2879870005 af ter 0ms
>> {2014-01-10 00:58:11,313} INFO
>> [account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738_watcher_executor]
>> (?:?) -
>> [account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738],
>> begin rebalancing consumer
>> account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738 try #1
>> {2014-01-10 00:58:11,314} DEBUG [catalina-exec-12-SendThread(
>> tvip-m1-mw-zookeeper.dish.com:2181)] (ClientCnxn.java:839) - Reading
>> reply sessionid:0x1437b2879870005, packet:: clientPath:null serverPath:null
>> finished:false header:: 627,8 replyHeader:: 627,51539619966,0 request::
>> '/brokers/ids,F response:: v{'1}
>> {2014-01-10 00:58:11,315} DEBUG [catalina-exec-12-SendThread(
>> tvip-m1-mw-zookeeper.dish.com:2181)] (ClientCnxn.java:839) - Reading
>> reply sessionid:0x1437b2879870005, packet:: clientPath:null serverPath:null
>> finished:false header:: 628,4 replyHeader:: 628,51539619966,0 request::
>> '/brokers/ids/1,F response::
>> #7b2022686f7374223a22746d312d6b61666b6162726f6b6572313031222c20226a6d785f706f7274223a393939392c2022706f7274223a393039322c202276657273696f6e223a31207d,s{47244644685,47244644685,1388537628753,1388537628753,0,0,0,163056791896588316,74,0,47244644685}
>> {2014-01-10 00:58:11,316} DEBUG [catalina-exec-12-SendThread(
>> tvip-m1-mw-zookeeper.dish.com:2181)] (ClientCnxn.java:839) - Reading
>> reply sessionid:0x1437b2879870005, packet:: clientPath:null serverPath:null
>> finished:false header:: 629,4 replyHeader:: 629,51539619966,-101
>> request::
>> '/consumers/account-activated-hadoop-consumer/ids/account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738,F
>> response::
>> {2014-01-10 00:58:11,316} INFO
>> [account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738_watcher_executor]
>> (?:?) -
>> [account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738],
>> exception during rebalance
>> org.I0Itec.zkclient.exception.ZkNoNodeException:
>> org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode =
>> NoNode for
>> /consumers/account-activated-hadoop-consumer/ids/account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738
>> at
>> org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
>> at
>> org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:685)
>> at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:766)
>> at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:761)
>> at kafka.utils.ZkUtils$.readData(Unknown Source)
>> at kafka.consumer.TopicCount$.constructTopicCount(Unknown Source)
>> at
>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(Unknown
>> Source)
>> at
>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply$mcVI$sp(Unknown
>> Source)
>> at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:142)
>> at
>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(Unknown
>> Source)
>> at
>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$1.run(Unknown
>> Source) Caused by: org.apache.zookeeper.KeeperException$NoNodeException:
>> KeeperErrorCode = NoNode for
>> /consumers/account-activated-hadoop-consumer/ids/account-activated-hadoop-consumer_tm1mwdpl04-1389222557906-562b6738
>> at
>> org.apache.zookeeper.KeeperException.create(KeeperException.java:102)
>> at
>> org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
>> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:956)
>> at org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:103)
>> :
>> -----Original Message-----
>> From: Guozhang Wang [mailto:wangg...@gmail.com]
>> Sent: Friday, January 10, 2014 12:30 PM
>> To: users@kafka.apache.org
>> Subject: Re: Looks like consumer fetchers get stopped we are not getting
>> any data
>>
>> Actually, the broken channel is broken by shutting down the
>> leader-finder-thread, which is shutdown either by a rebalance retry or
>> shutting down the consumer.
>>
>> Do you see "begin rebalance ..." before this log entry? And if yes, search
>> to see if the rebalance keep failing.
>>
>> Guozhang
>>
>>
>> On Fri, Jan 10, 2014 at 11:23 AM, Guozhang Wang <wangg...@gmail.com>
>> wrote:
>>
>>> From your logs the channel with the brokers are broken, are the
>>> brokers alive at that time?
>>>
>>> Guozhang
>>>
>>>
>>> On Fri, Jan 10, 2014 at 10:52 AM, Withers, Robert
>>> <robert.with...@dish.com
>>>> wrote:
>>>
>>>> The core problem is our consumers stop consuming and lag increases.
>>>> We found this blog:
>> https://cwiki.apache.org/confluence/display/KAFKA/FAQ#FAQ-Myconsumerseemstohavestopped,why
>> ?.
>>>> This lists 3 possibilities.
>>>>
>>>> The blog also talks earlier about spurious rebalances, due to
>>>> improper GC settings, but we couldn't find what GC settings to use.
>>>> We are considering changing the zookeeper timeouts. We are a little
>>>> confused about the various issues, the sequence of issues and what
>>>> could cause the consumers to stop reading. If the fetchers get
>>>> shutdown, due to a ClosedByInterruptException in the "leader_finder"
>>>> thread, which tells the "executor_watcher" thread to shutdown the
>>>> fetchers, that would be another reason the consumers stop processing
>> data. Is this possible?
>>>>
>>>> Thank you,
>>>> rob
>>>>
>>>> -----Original Message-----
>>>> From: Seshadri, Balaji [mailto:balaji.sesha...@dish.com]
>>>> Sent: Friday, January 10, 2014 11:40 AM
>>>> To: users@kafka.apache.org
>>>> Subject: RE: Looks like consumer fetchers get stopped we are not
>>>> getting any data
>>>>
>>>> It would be helpful if you guys can shed some light why all fetchers
>>>> are getting stopped.
>>>>
>>>> -----Original Message-----
>>>> From: Seshadri, Balaji [mailto:balaji.sesha...@dish.com]
>>>> Sent: Friday, January 10, 2014 11:28 AM
>>>> To: users@kafka.apache.org
>>>> Subject: RE: Looks like consumer fetchers get stopped we are not
>>>> getting any data
>>>>
>>>> We also got the below error when this happens.
>>>>
>>>> {2014-01-10 00:58:11,292} INFO
>>>>
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b_watcher_executor]
>>>> (?:?) -
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b],
>>>> exception during rebalance
>>>> org.I0Itec.zkclient.exception.ZkNoNodeException:
>>>> org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode
>>>> = NoNode for
>> /consumers/account-info-updated-hadoop-consumer/ids/account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad59660b
>>>> at
>>>> org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
>>>> at
>>>> org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:685)
>>>> at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:766)
>>>> at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:761)
>>>> at kafka.utils.ZkUtils$.readData(Unknown Source)
>>>> at kafka.consumer.TopicCount$.constructTopicCount(Unknown
>> Source)
>>>> at
>>>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$
>>>> consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(U
>>>> nknown
>>>> Source)
>>>> at
>>>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonf
>>>> un$syncedRebalance$1.apply$mcVI$sp(Unknown
>>>> Source)
>>>> at
>>>> scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:142)
>>>> at
>>>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.synced
>>>> Rebalance(Unknown
>>>> Source)
>>>> at
>>>> kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$
>>>> 1.run(Unknown
>>>> Source) Caused by: org.apache.zookeeper.KeeperException$NoNodeException:
>>>> KeeperErrorCode = NoNode for
>> /consumers/account-info-updated-hadoop-consumer/ids/account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad59660b
>>>> at
>>>> org.apache.zookeeper.KeeperException.create(KeeperException.java:102)
>>>> at
>>>> org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
>>>> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
>>>> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:956)
>>>> at
>>>> org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:103)
>>>> at org.I0Itec.zkclient.ZkClient$9.call(ZkClient.java:770)
>>>> at org.I0Itec.zkclient.ZkClient$9.call(ZkClient.java:766)
>>>> at
>>>> org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:675)
>>>> ... 9 more
>>>>
>>>> -----Original Message-----
>>>> From: Seshadri, Balaji [mailto:balaji.sesha...@dish.com]
>>>> Sent: Friday, January 10, 2014 10:52 AM
>>>> To: users@kafka.apache.org
>>>> Subject: Looks like consumer fetchers get stopped we are not getting
>>>> any data
>>>>
>>>> Please let us know why we are not getting any data from Kafaka after
>>>> this log from Kafka,can you guys lets us know.
>>>>
>>>> What could be causing all fetchers associated to be stooped why it is
>>>> not doing retry.
>>>>
>>>> {2014-01-10 00:58:09,284} WARN
>>>>
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b-leader-finder-thread]
>>>> (?:?) - Fetching topic metadata with correlation id 3 for topics
>>>> [Set(account-info-updated)] from broker
>>>> [id:1,host:tm1-kafkabroker101,port:9092] failed
>>>> java.nio.channels.ClosedByInterruptException
>>>> at
>> java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
>>>> at
>> sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:506)
>>>> at java.nio.channels.SocketChannel.write(SocketChannel.java:493)
>>>> at kafka.network.BoundedByteBufferSend.writeTo(Unknown Source)
>>>> at kafka.network.Send$class.writeCompletely(Unknown Source)
>>>> at
>>>> kafka.network.BoundedByteBufferSend.writeCompletely(Unknown
>>>> Source)
>>>> at kafka.network.BlockingChannel.send(Unknown Source)
>>>> at kafka.producer.SyncProducer.liftedTree1$1(Unknown Source)
>>>> at
>>>> kafka.producer.SyncProducer.kafka$producer$SyncProducer$$doSend(Unkno
>>>> wn
>>>> Source)
>>>> at kafka.producer.SyncProducer.send(Unknown Source)
>>>> at kafka.client.ClientUtils$.fetchTopicMetadata(Unknown Source)
>>>> at kafka.client.ClientUtils$.fetchTopicMetadata(Unknown Source)
>>>> at
>>>> kafka.consumer.ConsumerFetcherManager$LeaderFinderThread.doWork(Unkno
>>>> wn
>>>> Source)
>>>> at kafka.utils.ShutdownableThread.run(Unknown Source)
>>>> {2014-01-10 00:58:09,284} DEBUG
>>>> [account-access-hadoop-consumer_tm1mwdpl04-1389222551916-a0c87abc_wat
>>>> cher_executor]
>>>> (?:?) - initial fetch offset of account-access:27: fetched offset =
>> 9655:
>>>> consumed offset = 9655 is 9655
>>>> {2014-01-10 00:58:09,284} DEBUG
>>>> [bill-generated-hadoop-consumer_tm1mwdpl04-1389222547995-29a6dce9_wat
>>>> cher_executor]
>>>> (?:?) - initial consumer offset of bill-generated:11: fetched offset =
>> 152:
>>>> consumed offset = 152 is 152
>>>> {2014-01-10 00:58:09,284} DEBUG
>>>> [outbound-communications-hadoop-consumer_tm1mwdpl04-1389222550693-8bc
>>>> 34b77_watcher_executor]
>>>> (?:?) -
>>>> [outbound-communications-hadoop-consumer_tm1mwdpl04-1389222550693-8bc
>>>> 34b77],
>>>> outbound-communications:108: fetched offset = 1689: consumed offset =
>>>> 1689 selected new offset 1689
>>>> {2014-01-10 00:58:09,284} DEBUG [catalina-exec-3-SendThread(
>>>> tvip-m1-mw-zookeeper.dish.com:2181)] (ClientCnxn.java:839) - Reading
>>>> reply sessionid:0x1434b49cf56383b, packet:: clientPath:null
>>>> serverPath:null finished:false header:: 279,4 replyHeader::
>> 279,51539617506,0 request::
>>>> '/consumers/outbound-call-attempted-hadoop-consumer/offsets/outbound-
>>>> call-attempted/14,F
>>>> response::
>>>> #30,s{39860186414,39860186414,1387517714994,1387517714994,0,0,0,0,1,0
>>>> ,39860186414}
>>>> {2014-01-10 00:58:09,285} INFO
>>>>
>>>> [outbound-communications-hadoop-consumer_tm1mwdpl04-1389222550693-8bc
>>>> 34b77_watcher_executor]
>>>> (?:?) -
>>>> [outbound-communications-hadoop-consumer_tm1mwdpl04-1389222550693-8bc
>>>> 34b77],
>>>> outbound-communications-hadoop-consumer_tm1mwdpl04-1389222550693-8bc3
>>>> 4b77-3
>>>> attempting to claim partition 109
>>>> {2014-01-10 00:58:09,284} DEBUG
>>>> [bill-generated-hadoop-consumer_tm1mwdpl04-1389222547995-29a6dce9_wat
>>>> cher_executor]
>>>> (?:?) - initial fetch offset of bill-generated:11: fetched offset = 152:
>>>> consumed offset = 152 is 152
>>>> {2014-01-10 00:58:09,284} DEBUG [catalina-exec-12-SendThread(
>>>> tvip-m1-mw-zookeeper.dish.com:2181)] (ClientCnxn.java:839) - Reading
>>>> reply sessionid:0x1437b2879870005, packet:: clientPath:null
>>>> serverPath:null finished:false header:: 619,1 replyHeader::
>> 619,51539617508,0 request::
>>>> '/consumers/account-activated-hadoop-consumer/owners/account-activate
>>>> d/68,#6163636f756e742d6163746976617465642d6861646f6f702d636f6e73756d6
>>>> 5725f746d316d7764706c30342d313338393232323535373930362d35363262363733
>>>> 382d30,v{s{31,s{'world,'anyone}}},1
>>>> response::
>>>> '/consumers/account-activated-hadoop-consumer/owners/account-activate
>>>> d/68
>>>> {2014-01-10 00:58:09,284} DEBUG
>>>> [account-access-hadoop-consumer_tm1mwdpl04-1389222551916-a0c87abc_wat
>>>> cher_executor]
>>>> (?:?) -
>>>> [account-access-hadoop-consumer_tm1mwdpl04-1389222551916-a0c87abc],
>>>> account-access:27: fetched offset = 9655: consumed offset = 9655
>>>> selected new offset 9655
>>>> {2014-01-10 00:58:09,284} INFO
>>>>
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b_watcher_executor]
>>>> (?:?) -
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b-leader-finder-thread],
>>>> Shutdown completed
>>>> {2014-01-10 00:58:09,284} INFO
>>>>
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b-leader-finder-thread]
>>>> (?:?) -
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b-leader-finder-thread],
>>>> Stopped
>>>> {2014-01-10 00:58:09,285} INFO
>>>>
>>>> [account-info-updated-hadoop-consumer_tm1mwdpl04-1389222553159-ad5966
>>>> 0b_watcher_executor]
>>>> (?:?) - [ConsumerFetcherManager-1389222553163] Stopping all fetchers
>>>
>>>
>>> --
>>> -- Guozhang
>>
>>
>>
>> --
>> -- Guozhang
>>
>>
{2014-01-11 14:51:47,904} INFO [main] (?:?) - Disconnecting from
TESTSERVER:9092
{2014-01-11 14:51:47,904} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] Stopping leader finder thread
{2014-01-11 14:51:47,905} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] Stopping all fetchers
{2014-01-11 14:51:47,905} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] All connections stopped
{2014-01-11 14:51:47,905} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Cleared all relevant queues for this fetcher
{2014-01-11 14:51:47,906} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Cleared the data chunks in all the consumer message iterators
{2014-01-11 14:51:47,906} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Committing all offsets after clearing the fetcher queues
{2014-01-11 14:51:47,906} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Releasing partition ownership
{2014-01-11 14:51:47,907} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Consumer
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace
rebalancing the following partitions: ArrayBuffer(0, 1, 2, 3, 4, 5, 6, 7, 8, 9,
10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20, 21, 22, 23, 24, 25, 26, 27, 28, 29,
30, 31, 32, 33, 34, 35, 36, 37, 38, 39, 40, 41, 42, 43, 44, 45, 46, 47, 48, 49,
50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68, 69,
70, 71, 72, 73, 74, 75, 76, 77, 78, 79, 80, 81, 82, 83, 84, 85, 86, 87, 88, 89,
90, 91, 92, 93, 94, 95, 96, 97, 98, 99, 100, 101, 102, 103, 104, 105, 106, 107,
108, 109, 110, 111, 112, 113, 114, 115, 116, 117, 118, 119, 120, 121, 122, 123,
124, 125, 126, 127, 128, 129, 130) for topic account-info-updated with
consumers:
List(account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0,
account-info-updated-hadoop-consumer_tm1mwdpl03-1389473542645-d7a36e74-0,
account-info-updated-hadoop-consumer_tm1mwdpl03-1389473542645-d7a36e74-1,
account-info-updated-hadoop-consumer_tm1mwdpl03-1389473542645-d7a36e74-2,
account-info-updated-hadoop-consumer_tm1mwdpl03-1389473542645-d7a36e74-3,
account-info-updated-hadoop-consumer_tm1mwdpl04-1389474314490-b2546e82-0,
account-info-updated-hadoop-consumer_tm1mwdpl04-1389474314490-b2546e82-1,
account-info-updated-hadoop-consumer_tm1mwdpl04-1389474314490-b2546e82-2,
account-info-updated-hadoop-consumer_tm1mwdpl04-1389474314490-b2546e82-3)
{2014-01-11 14:51:47,907} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 0
{2014-01-11 14:51:47,909} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 1
{2014-01-11 14:51:47,911} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 2
{2014-01-11 14:51:47,913} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 3
{2014-01-11 14:51:47,915} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 4
{2014-01-11 14:51:47,917} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 5
{2014-01-11 14:51:47,918} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 6
{2014-01-11 14:51:47,920} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 7
{2014-01-11 14:51:47,922} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 8
{2014-01-11 14:51:47,924} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 9
{2014-01-11 14:51:47,926} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 10
{2014-01-11 14:51:47,928} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 11
{2014-01-11 14:51:47,930} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 12
{2014-01-11 14:51:47,931} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 13
{2014-01-11 14:51:47,933} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
attempting to claim partition 14
{2014-01-11 14:51:47,939} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/3
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,939} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 3
{2014-01-11 14:51:47,942} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/1
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,948} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 1
{2014-01-11 14:51:47,952} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/13
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,952} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 13
{2014-01-11 14:51:47,955} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/0
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,955} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 0
{2014-01-11 14:51:47,959} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/8
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,959} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 8
{2014-01-11 14:51:47,962} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/10
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,962} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 10
{2014-01-11 14:51:47,966} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/12
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,966} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 12
{2014-01-11 14:51:47,970} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/9
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,970} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 9
{2014-01-11 14:51:47,974} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/5
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,974} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 5
{2014-01-11 14:51:47,977} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/4
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,978} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 4
{2014-01-11 14:51:47,981} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/7
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,981} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 7
{2014-01-11 14:51:47,984} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/14
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,985} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 14
{2014-01-11 14:51:47,988} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/2
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,988} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 2
{2014-01-11 14:51:47,991} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/11
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,992} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 11
{2014-01-11 14:51:47,995} INFO [main] (?:?) - conflict in
/consumers/account-info-updated-hadoop-consumer/owners/account-info-updated/6
data:
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace-0
stored data:
account-info-updated-hadoop-consumer_tm1mwdpl03-1383065274091-95b889f8-0
{2014-01-11 14:51:47,995} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
waiting for the partition ownership to be deleted: 6
{2014-01-11 14:51:47,995} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace], end
rebalancing consumer
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace try #1
{2014-01-11 14:51:47,995} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Rebalancing attempt failed. Clearing the cache before the next rebalancing
operation is triggered
{2014-01-11 14:51:47,996} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] Stopping leader finder thread
{2014-01-11 14:51:47,996} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] Stopping all fetchers
{2014-01-11 14:51:47,996} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] All connections stopped
{2014-01-11 14:51:47,996} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Cleared all relevant queues for this fetcher
{2014-01-11 14:51:47,996} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Cleared the data chunks in all the consumer message iterators
{2014-01-11 14:51:47,996} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
Committing all offsets after clearing the fetcher queues
{2014-01-11 14:51:49,998} INFO [main] (?:?) -
[account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace],
begin rebalancing consumer
account-info-updated-hadoop-consumer_MERD7-189197-1389477104841-89aadace try #2
{2014-01-11 14:51:50,037} INFO [main] (?:?) - Verifying properties
{2014-01-11 14:51:50,037} INFO [main] (?:?) - Property metadata.broker.list is
overridden to TESTSERVER:9092
{2014-01-11 14:51:50,037} INFO [main] (?:?) - Property request.timeout.ms is
overridden to 30000
{2014-01-11 14:51:50,038} INFO [main] (?:?) - Property client.id is overridden
to account-info-updated-hadoop-consumer
{2014-01-11 14:51:50,038} INFO [main] (?:?) - Fetching metadata from broker
id:1,host:TESTSERVER,port:9092 with correlation id 2 for 1 topic(s)
Set(account-info-updated)
{2014-01-11 14:51:50,040} INFO [main] (?:?) - Connected to TESTSERVER:9092 for
producing
{2014-01-11 14:51:50,053} INFO [main] (?:?) - Disconnecting from
TESTSERVER:9092
{2014-01-11 14:51:50,053} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] Stopping leader finder thread
{2014-01-11 14:51:50,053} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] Stopping all fetchers
{2014-01-11 14:51:50,054} INFO [main] (?:?) -
[ConsumerFetcherManager-1389477104931] All connections stopped
