You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@kafka.apache.org by "xiaoguy (JIRA)" <ji...@apache.org> on 2017/06/08 01:51:18 UTC
[jira] [Updated] (KAFKA-5406) NoNodeException result in rebalance
failed
[ https://issues.apache.org/jira/browse/KAFKA-5406?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
xiaoguy updated KAFKA-5406:
---------------------------
Attachment: log.log
Description:
hey guys , I got this problem this days,
because of the network is unstable， consumer rebalance failed after 5 times ,the log shows that zk path /consumers/$(groupIdName)/ids/ is null,
consumer seems can't register after network recovered, so i got the kafka source code (0.8.2.2) and found the consumer/ZookeeperConsumerConnector$ZKSessionExpireListener handleNewSession won't call , and handleStateChanged do nothing,
so i change the code like this ,and it seems works , and i checked 0.10.0.0 version, the same problem, is this a bug ? i'm confused , thank you.
def handleStateChanged(state: KeeperState) {
// do nothing, since zkclient will do reconnect for us.
if(state==KeeperState.SyncConnected){
handleNewSession()
}
System.err.println("----------------ZKSessionExpireListener------------ handleStateChanged-----state:"+state+"----"+state.getIntValue)
}
was:
hey guys , I got this problem this days,
because of the network is unstable， consumer rebalance failed after 5 times ,the log shows that zk path /consumers/$(groupIdName)/ids/ is null,
consumer seems can't register after network recovered, so i got the kafka source code (0.8.2.2) and found the consumer/ZookeeperConsumerConnector$ZKSessionExpireListener handleNewSession won't call , and handleStateChanged do nothing,
so i change the code like this ,and it seems works , and i checked 0.10.0.0 version, the same problem, is this a bug ? i'm confused , thank you.
def handleStateChanged(state: KeeperState) {
// do nothing, since zkclient will do reconnect for us.
if(state==KeeperState.SyncConnected){
handleNewSession()
}
System.err.println("----------------ZKSessionExpireListener------------ handleStateChanged-----state:"+state+"----"+state.getIntValue)
}
, the log as follows
2017-06-08 05:23:43 [ main-SendThread():78987 ] - [ INFO ] Client session timed out, have not heard from server in 11801ms for sessionid 0x1571d0f893900d3, closing socket connection and attempting reconnect
2017-06-08 05:23:43 [ main-SendThread():78987 ] - [ DEBUG ] Ignoring exception during shutdown input
java.net.SocketException: Socket is not connected
at sun.nio.ch.Net.translateToSocketException(Net.java:149)
at sun.nio.ch.Net.translateException(Net.java:183)
at sun.nio.ch.Net.translateException(Net.java:189)
at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:428)
at org.apache.zookeeper.ClientCnxnSocketNIO.cleanup(ClientCnxnSocketNIO.java:126)
at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1161)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1101)
Caused by: java.nio.channels.NotYetConnectedException
at sun.nio.ch.SocketChannelImpl.shutdownInput(SocketChannelImpl.java:804)
at sun.nio.ch.SocketAdaptor.shutdownInput(SocketAdaptor.java:426)
... 3 more
2017-06-08 05:23:43 [ main-SendThread():78987 ] - [ DEBUG ] Ignoring exception during shutdown output
java.net.SocketException: Socket is not connected
at sun.nio.ch.Net.translateToSocketException(Net.java:149)
at sun.nio.ch.Net.translateException(Net.java:183)
at sun.nio.ch.Net.translateException(Net.java:189)
at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:436)
at org.apache.zookeeper.ClientCnxnSocketNIO.cleanup(ClientCnxnSocketNIO.java:133)
at org.apache.zookeeper.ClientCnxn$SendThread.cleanup(ClientCnxn.java:1161)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1101)
Caused by: java.nio.channels.NotYetConnectedException
at sun.nio.ch.SocketChannelImpl.shutdownOutput(SocketChannelImpl.java:821)
at sun.nio.ch.SocketAdaptor.shutdownOutput(SocketAdaptor.java:434)
... 3 more
2017-06-08 05:23:43 [ main-SendThread():79087 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 39,8 replyHeader:: 0,0,-4 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:43 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:79088 ] - [ INFO ] Waiting for keeper state SyncConnected
2017-06-08 05:23:45 [ main-SendThread():80565 ] - [ INFO ] Opening socket connection to server /192.168.5.206:2181
2017-06-08 05:23:45 [ main-SendThread():80582 ] - [ INFO ] Socket connection established to /192.168.5.206:2181, initiating session
2017-06-08 05:23:45 [ main-SendThread():80583 ] - [ DEBUG ] Session establishment request sent on /192.168.5.206:2181
2017-06-08 05:23:45 [ main-SendThread():80594 ] - [ WARN ] the session has expried, reconnect to create a new session
2017-06-08 05:23:45 [ main-SendThread():80594 ] - [ INFO ] Unable to reconnect to ZooKeeper service, session 0x1571d0f893900d3 has expired, closing socket connection
2017-06-08 05:23:45 [ main-SendThread():80695 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: -8,101 replyHeader:: 0,0,-4 request:: 27120,v{'/zk10/consumers/abadd22221aaa1/ids,'/zk10/brokers/topics/KT_0323_WPXwqq522K65ImU1Epa9f8aab},v{},v{'/zk10/consumers/abadd22221aaa1/ids} response:: null
2017-06-08 05:23:45 [ main-SendThread():80696 ] - [ DEBUG ] delete pack from pendingQueue,clientPath:null serverPath:null finished:true header:: -8,101 replyHeader:: 0,0,-4 request:: 27120,v{'/zk10/consumers/abadd22221aaa1/ids,'/zk10/brokers/topics/KT_0323_WPXwqq522K65ImU1Epa9f8aab},v{},v{'/zk10/consumers/abadd22221aaa1/ids} response:: null
2017-06-08 05:23:46 [ main-SendThread():82036 ] - [ INFO ] Opening socket connection to server /192.168.5.206:2181
2017-06-08 05:23:46 [ main-SendThread():82046 ] - [ INFO ] Socket connection established to /192.168.5.206:2181, initiating session
2017-06-08 05:23:46 [ main-SendThread():82046 ] - [ DEBUG ] Session establishment request sent on /192.168.5.206:2181
2017-06-08 05:23:46 [ main-SendThread():82059 ] - [ INFO ] Session establishment complete on server /192.168.5.206:2181, sessionid = 0x1571d0f893900d4, negotiated timeout = 10000
2017-06-08 05:23:46 [ main-EventThread:82060 ] - [ DEBUG ] Received event: WatchedEvent state:SyncConnected type:None path:null
2017-06-08 05:23:46 [ main-EventThread:82060 ] - [ INFO ] zookeeper state changed (SyncConnected)
2017-06-08 05:23:46 [ main-EventThread:82060 ] - [ DEBUG ] New event: ZkEvent[State changed to SyncConnected sent to kafka.consumer.ZookeeperConsumerConnector$ZKSessionExpireListener@5ebd50b9]
2017-06-08 05:23:46 [ main-EventThread:82060 ] - [ DEBUG ] Leaving process event
2017-06-08 05:23:46 [ ZkClient-EventThread-13-192.168.5.206:2181/zk10:82060 ] - [ DEBUG ] Delivering event #2 ZkEvent[State changed to SyncConnected sent to kafka.consumer.ZookeeperConsumerConnector$ZKSessionExpireListener@5ebd50b9]
2017-06-08 05:23:46 [ ZkClient-EventThread-13-192.168.5.206:2181/zk10:82060 ] - [ DEBUG ] Delivering event #2 done
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82060 ] - [ DEBUG ] State is SyncConnected
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82061 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 40,8 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:46 [ main-SendThread():82082 ] - [ DEBUG ] Got notification sessionid:0x1571d0f893900d4
2017-06-08 05:23:46 [ main-SendThread():82083 ] - [ DEBUG ] Got WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/consumers/abadd22221aaa1/ids for sessionid 0x1571d0f893900d4
2017-06-08 05:23:46 [ main-EventThread:82083 ] - [ DEBUG ] Received event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/consumers/abadd22221aaa1/ids
2017-06-08 05:23:46 [ main-EventThread:82084 ] - [ DEBUG ] New event: ZkEvent[Children of /consumers/abadd22221aaa1/ids changed sent to kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener@2b4ba0fe]
2017-06-08 05:23:46 [ main-EventThread:82084 ] - [ DEBUG ] Leaving process event
2017-06-08 05:23:46 [ ZkClient-EventThread-13-192.168.5.206:2181/zk10:82084 ] - [ DEBUG ] Delivering event #3 ZkEvent[Children of /consumers/abadd22221aaa1/ids changed sent to kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener@2b4ba0fe]
2017-06-08 05:23:46 [ main-SendThread():82084 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: -8,101 replyHeader:: -8,27122,0 request:: 27120,v{'/zk10/consumers/abadd22221aaa1/ids,'/zk10/brokers/topics/KT_0323_WPXwqq522K65ImU1Epa9f8aab},v{},v{'/zk10/consumers/abadd22221aaa1/ids} response:: null
2017-06-08 05:23:46 [ ZkClient-EventThread-13-192.168.5.206:2181/zk10:82084 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 41,3 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids,T response::
2017-06-08 05:23:46 [ main-SendThread():82084 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: -8,101 replyHeader:: -8,27122,0 request:: 27120,v{'/zk10/consumers/abadd22221aaa1/ids,'/zk10/brokers/topics/KT_0323_WPXwqq522K65ImU1Epa9f8aab},v{},v{'/zk10/consumers/abadd22221aaa1/ids} response:: null
2017-06-08 05:23:46 [ main-SendThread():82108 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 40,8 replyHeader:: 40,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:46 [ main-SendThread():82108 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 40,8 replyHeader:: 40,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82109 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 42,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/0,F response::
2017-06-08 05:23:46 [ main-SendThread():82137 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 41,3 replyHeader:: 41,27122,0 request:: '/zk10/consumers/abadd22221aaa1/ids,T response:: s{27078,27078,1496848777682,1496848777682,0,8,0,0,0,0,27121}
2017-06-08 05:23:46 [ main-SendThread():82138 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 41,3 replyHeader:: 41,27122,0 request:: '/zk10/consumers/abadd22221aaa1/ids,T response:: s{27078,27078,1496848777682,1496848777682,0,8,0,0,0,0,27121}
2017-06-08 05:23:46 [ ZkClient-EventThread-13-192.168.5.206:2181/zk10:82138 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 43,8 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids,T response:: v{}
2017-06-08 05:23:46 [ main-SendThread():82162 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 42,4 replyHeader:: 42,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:46 [ main-SendThread():82162 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 42,4 replyHeader:: 42,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82178 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 44,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/1,F response::
2017-06-08 05:23:46 [ main-SendThread():82187 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 43,8 replyHeader:: 43,27122,0 request:: '/zk10/consumers/abadd22221aaa1/ids,T response:: v{}
2017-06-08 05:23:46 [ main-SendThread():82187 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 43,8 replyHeader:: 43,27122,0 request:: '/zk10/consumers/abadd22221aaa1/ids,T response:: v{}
2017-06-08 05:23:46 [ ZkClient-EventThread-13-192.168.5.206:2181/zk10:82189 ] - [ DEBUG ] Delivering event #3 done
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82189 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], begin rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #0
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82189 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 45,8 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:46 [ main-SendThread():82200 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 44,4 replyHeader:: 44,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:46 [ main-SendThread():82200 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 44,4 replyHeader:: 44,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82207 ] - [ INFO ] Verifying properties
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82208 ] - [ INFO ] Property client.id is overridden to abadd22221aaa1
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82208 ] - [ INFO ] Property metadata.broker.list is overridden to Master:9094,Master:9095
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82208 ] - [ INFO ] Property request.timeout.ms is overridden to 30000
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82209 ] - [ INFO ] Fetching metadata from broker BrokerEndPoint(0,Master,9094) with correlation id 1 for 1 topic(s) Set(KT_0323_WPXwqq522K65ImU1Epa9f8aab)
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82238 ] - [ DEBUG ] Created socket with SO_TIMEOUT = 30000 (requested 30000), SO_RCVBUF = 65536 (requested -1), SO_SNDBUF = 102400 (requested 102400), connectTimeoutMs = 30000.
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82238 ] - [ INFO ] Connected to Master:9094 for producing
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82250 ] - [ INFO ] Disconnecting from Master:9094
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82251 ] - [ DEBUG ] Successfully fetched metadata for 1 topic(s) Set(KT_0323_WPXwqq522K65ImU1Epa9f8aab)
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82251 ] - [ DEBUG ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread], {TopicMetadata for topic KT_0323_WPXwqq522K65ImU1Epa9f8aab ->
Metadata for partition [KT_0323_WPXwqq522K65ImU1Epa9f8aab,0] is partition 0 leader: BrokerEndPoint(0,Master,9094) replicas: BrokerEndPoint(0,Master,9094) isr: BrokerEndPoint(0,Master,9094) isUnderReplicated: false}
2017-06-08 05:23:46 [ ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0:82252 ] - [ INFO ] Reconnect due to error:
java.nio.channels.ClosedChannelException
at kafka.network.BlockingChannel.send(BlockingChannel.scala:110)
at kafka.consumer.SimpleConsumer.liftedTree1$1(SimpleConsumer.scala:85)
at kafka.consumer.SimpleConsumer.kafka$consumer$SimpleConsumer$$sendRequest(SimpleConsumer.scala:83)
at kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(SimpleConsumer.scala:132)
at kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(SimpleConsumer.scala:132)
at kafka.consumer.SimpleConsumer$$anonfun$fetch$1$$anonfun$apply$mcV$sp$1.apply(SimpleConsumer.scala:132)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply$mcV$sp(SimpleConsumer.scala:131)
at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(SimpleConsumer.scala:131)
at kafka.consumer.SimpleConsumer$$anonfun$fetch$1.apply(SimpleConsumer.scala:131)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.SimpleConsumer.fetch(SimpleConsumer.scala:130)
at kafka.consumer.ConsumerFetcherThread.fetch(ConsumerFetcherThread.scala:108)
at kafka.consumer.ConsumerFetcherThread.fetch(ConsumerFetcherThread.scala:29)
at kafka.server.AbstractFetcherThread.processFetchRequest(AbstractFetcherThread.scala:107)
at kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:98)
at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:63)
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82252 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Added fetcher for partitions ArrayBuffer([[KT_0323_WPXwqq522K65ImU1Epa9f8aab,0], initOffset 462 to broker BrokerEndPoint(0,Master,9094)] )
2017-06-08 05:23:46 [ ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0:82252 ] - [ DEBUG ] Disconnecting from Master:9094
2017-06-08 05:23:46 [ ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0:82253 ] - [ DEBUG ] Disconnecting from Master:9094
2017-06-08 05:23:46 [ main-SendThread():82260 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 45,8 replyHeader:: 45,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:46 [ main-SendThread():82260 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 45,8 replyHeader:: 45,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82261 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 46,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/1,F response::
2017-06-08 05:23:46 [ ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0:82263 ] - [ DEBUG ] Created socket with SO_TIMEOUT = 30000 (requested 30000), SO_RCVBUF = 65536 (requested 65536), SO_SNDBUF = 65536 (requested -1), connectTimeoutMs = 30000.
2017-06-08 05:23:46 [ main-SendThread():82273 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 46,4 replyHeader:: 46,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:46 [ main-SendThread():82273 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 46,4 replyHeader:: 46,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82284 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 47,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/0,F response::
2017-06-08 05:23:46 [ main-SendThread():82304 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 47,4 replyHeader:: 47,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:46 [ main-SendThread():82305 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 47,4 replyHeader:: 47,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82313 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 48,4 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:46 [ main-SendThread():82324 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 48,4 replyHeader:: 48,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:46 [ main-SendThread():82324 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 48,4 replyHeader:: 48,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82326 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], exception during rebalance
org.I0Itec.zkclient.exception.ZkNoNodeException: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1000)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1094)
at kafka.utils.ZkUtils.readData(ZkUtils.scala:542)
at kafka.consumer.TopicCount$.constructTopicCount(TopicCount.scala:61)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(ZookeeperConsumerConnector.scala:674)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1$$anonfun$apply$mcV$sp$1.apply$mcVI$sp(ZookeeperConsumerConnector.scala:646)
at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:141)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply$mcV$sp(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(ZookeeperConsumerConnector.scala:636)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$2.run(ZookeeperConsumerConnector.scala:589)
Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1131)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1160)
at org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:124)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1103)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:990)
... 13 more
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82327 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], end rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #0
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82328 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Rebalancing attempt failed. Clearing the cache before the next rebalancing operation is triggered
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82330 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping leader finder thread
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82330 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread], Shutting down
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82332 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread], Shutdown completed
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82332 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping all fetchers
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread:82332 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-leader-finder-thread], Stopped
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82332 ] - [ INFO ] [ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0], Shutting down
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82333 ] - [ DEBUG ] Disconnecting from Master:9094
2017-06-08 05:23:46 [ ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0:82334 ] - [ DEBUG ] Disconnecting from Master:9094
2017-06-08 05:23:46 [ ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0:82334 ] - [ INFO ] [ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0], Stopped
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82335 ] - [ INFO ] [ConsumerFetcherThread-abadd22221aaa1_OO_oo-1496870544934-ee22c3ca-0-0], Shutdown completed
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82346 ] - [ DEBUG ] Disconnecting from Master:9094
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82346 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] All connections stopped
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82347 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared all relevant queues for this fetcher
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82347 ] - [ DEBUG ] Clearing the current data chunk for this consumer iterator
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82347 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared the data chunks in all the consumer message iterators
2017-06-08 05:23:46 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:82347 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Committing all offsets after clearing the fetcher queues
2017-06-08 05:23:48 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84347 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], begin rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #1
2017-06-08 05:23:48 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84347 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 49,8 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:49 [ main-SendThread():84657 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 49,8 replyHeader:: 49,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:49 [ main-SendThread():84658 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 49,8 replyHeader:: 49,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84658 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 50,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/1,F response::
2017-06-08 05:23:49 [ main-SendThread():84669 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 50,4 replyHeader:: 50,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:49 [ main-SendThread():84669 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 50,4 replyHeader:: 50,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84682 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 51,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/0,F response::
2017-06-08 05:23:49 [ main-SendThread():84693 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 51,4 replyHeader:: 51,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:49 [ main-SendThread():84693 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 51,4 replyHeader:: 51,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84703 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 52,4 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:49 [ main-SendThread():84713 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 52,4 replyHeader:: 52,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:49 [ main-SendThread():84714 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 52,4 replyHeader:: 52,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84715 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], exception during rebalance
org.I0Itec.zkclient.exception.ZkNoNodeException: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1000)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1094)
at kafka.utils.ZkUtils.readData(ZkUtils.scala:542)
at kafka.consumer.TopicCount$.constructTopicCount(TopicCount.scala:61)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(ZookeeperConsumerConnector.scala:674)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1$$anonfun$apply$mcV$sp$1.apply$mcVI$sp(ZookeeperConsumerConnector.scala:646)
at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:141)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply$mcV$sp(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(ZookeeperConsumerConnector.scala:636)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$2.run(ZookeeperConsumerConnector.scala:589)
Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1131)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1160)
at org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:124)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1103)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:990)
... 13 more
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], end rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #1
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Rebalancing attempt failed. Clearing the cache before the next rebalancing operation is triggered
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping leader finder thread
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping all fetchers
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] All connections stopped
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared all relevant queues for this fetcher
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84716 ] - [ DEBUG ] Clearing the current data chunk for this consumer iterator
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84717 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared the data chunks in all the consumer message iterators
2017-06-08 05:23:49 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:84717 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Committing all offsets after clearing the fetcher queues
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86718 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], begin rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #2
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86718 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 53,8 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:51 [ main-SendThread():86730 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 53,8 replyHeader:: 53,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:51 [ main-SendThread():86730 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 53,8 replyHeader:: 53,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86731 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 54,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/1,F response::
2017-06-08 05:23:51 [ main-SendThread():86741 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 54,4 replyHeader:: 54,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:51 [ main-SendThread():86742 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 54,4 replyHeader:: 54,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86747 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 55,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/0,F response::
2017-06-08 05:23:51 [ main-SendThread():86757 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 55,4 replyHeader:: 55,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:51 [ main-SendThread():86757 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 55,4 replyHeader:: 55,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86762 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 56,4 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:51 [ main-SendThread():86774 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 56,4 replyHeader:: 56,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:51 [ main-SendThread():86774 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 56,4 replyHeader:: 56,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86774 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], exception during rebalance
org.I0Itec.zkclient.exception.ZkNoNodeException: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1000)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1094)
at kafka.utils.ZkUtils.readData(ZkUtils.scala:542)
at kafka.consumer.TopicCount$.constructTopicCount(TopicCount.scala:61)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(ZookeeperConsumerConnector.scala:674)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1$$anonfun$apply$mcV$sp$1.apply$mcVI$sp(ZookeeperConsumerConnector.scala:646)
at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:141)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply$mcV$sp(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(ZookeeperConsumerConnector.scala:636)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$2.run(ZookeeperConsumerConnector.scala:589)
Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1131)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1160)
at org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:124)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1103)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:990)
... 13 more
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], end rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #2
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Rebalancing attempt failed. Clearing the cache before the next rebalancing operation is triggered
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping leader finder thread
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping all fetchers
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] All connections stopped
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared all relevant queues for this fetcher
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ DEBUG ] Clearing the current data chunk for this consumer iterator
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared the data chunks in all the consumer message iterators
2017-06-08 05:23:51 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:86775 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Committing all offsets after clearing the fetcher queues
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88777 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], begin rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #3
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88777 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 57,8 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:53 [ main-SendThread():88788 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 57,8 replyHeader:: 57,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:53 [ main-SendThread():88788 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 57,8 replyHeader:: 57,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88789 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 58,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/1,F response::
2017-06-08 05:23:53 [ main-SendThread():88799 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 58,4 replyHeader:: 58,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:53 [ main-SendThread():88800 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 58,4 replyHeader:: 58,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88804 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 59,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/0,F response::
2017-06-08 05:23:53 [ main-SendThread():88817 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 59,4 replyHeader:: 59,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:53 [ main-SendThread():88818 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 59,4 replyHeader:: 59,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88822 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 60,4 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:53 [ main-SendThread():88834 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 60,4 replyHeader:: 60,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:53 [ main-SendThread():88835 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 60,4 replyHeader:: 60,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88835 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], exception during rebalance
org.I0Itec.zkclient.exception.ZkNoNodeException: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1000)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1094)
at kafka.utils.ZkUtils.readData(ZkUtils.scala:542)
at kafka.consumer.TopicCount$.constructTopicCount(TopicCount.scala:61)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(ZookeeperConsumerConnector.scala:674)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1$$anonfun$apply$mcV$sp$1.apply$mcVI$sp(ZookeeperConsumerConnector.scala:646)
at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:141)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply$mcV$sp(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(ZookeeperConsumerConnector.scala:636)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$2.run(ZookeeperConsumerConnector.scala:589)
Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1131)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1160)
at org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:124)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1103)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:990)
... 13 more
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88836 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], end rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #3
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88836 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Rebalancing attempt failed. Clearing the cache before the next rebalancing operation is triggered
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88836 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping leader finder thread
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88836 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping all fetchers
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88836 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] All connections stopped
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88836 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared all relevant queues for this fetcher
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88837 ] - [ DEBUG ] Clearing the current data chunk for this consumer iterator
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88837 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared the data chunks in all the consumer message iterators
2017-06-08 05:23:53 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:88837 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Committing all offsets after clearing the fetcher queues
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90837 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], begin rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #4
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90837 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 61,8 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids,F response:: v{}
2017-06-08 05:23:55 [ main-SendThread():90849 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 61,8 replyHeader:: 61,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:55 [ main-SendThread():90850 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 61,8 replyHeader:: 61,27122,0 request:: '/zk10/brokers/ids,F response:: v{'1,'0}
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90850 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 62,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/1,F response::
2017-06-08 05:23:55 [ main-SendThread():90865 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 62,4 replyHeader:: 62,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:55 [ main-SendThread():90866 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 62,4 replyHeader:: 62,27122,0 request:: '/zk10/brokers/ids/1,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363331363134222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303935225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039357d,s{27068,27068,1496848631622,1496848631622,0,0,0,96577869575684302,123,0,27068}
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90875 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 63,4 replyHeader:: 0,0,0 request:: '/zk10/brokers/ids/0,F response::
2017-06-08 05:23:55 [ main-SendThread():90886 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 63,4 replyHeader:: 63,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:55 [ main-SendThread():90887 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 63,4 replyHeader:: 63,27122,0 request:: '/zk10/brokers/ids/0,F response:: #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343936383438363136303536222c22656e64706f696e7473223a5b22504c41494e544558543a2f2f4d61737465723a39303934225d2c22686f7374223a224d6173746572222c2276657273696f6e223a332c22706f7274223a393039347d,s{27062,27062,1496848616067,1496848616067,0,0,0,96577869575684300,123,0,27062}
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90903 ] - [ DEBUG ] enqueue outgoingQueue packet, canSend=true, isPingOrClose=false, clientPath:null serverPath:null finished:false header:: 64,4 replyHeader:: 0,0,0 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:55 [ main-SendThread():90915 ] - [ DEBUG ] Reading reply sessionid:0x1571d0f893900d4, packet:: clientPath:null serverPath:null finished:false header:: 64,4 replyHeader:: 64,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:55 [ main-SendThread():90917 ] - [ DEBUG ] finishPacket p=clientPath:null serverPath:null finished:false header:: 64,4 replyHeader:: 64,27122,-101 request:: '/zk10/consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca,F response::
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90920 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], exception during rebalance
org.I0Itec.zkclient.exception.ZkNoNodeException: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.I0Itec.zkclient.exception.ZkException.create(ZkException.java:47)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:1000)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.readData(ZkClient.java:1094)
at kafka.utils.ZkUtils.readData(ZkUtils.scala:542)
at kafka.consumer.TopicCount$.constructTopicCount(TopicCount.scala:61)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.kafka$consumer$ZookeeperConsumerConnector$ZKRebalancerListener$$rebalance(ZookeeperConsumerConnector.scala:674)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1$$anonfun$apply$mcV$sp$1.apply$mcVI$sp(ZookeeperConsumerConnector.scala:646)
at scala.collection.immutable.Range.foreach$mVc$sp(Range.scala:141)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply$mcV$sp(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anonfun$syncedRebalance$1.apply(ZookeeperConsumerConnector.scala:637)
at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:33)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(ZookeeperConsumerConnector.scala:636)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$2.run(ZookeeperConsumerConnector.scala:589)
Caused by: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /consumers/abadd22221aaa1/ids/abadd22221aaa1_OO_oo-1496870544934-ee22c3ca
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1131)
at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1160)
at org.I0Itec.zkclient.ZkConnection.readData(ZkConnection.java:124)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1103)
at org.I0Itec.zkclient.ZkClient$12.call(ZkClient.java:1099)
at org.I0Itec.zkclient.ZkClient.retryUntilConnected(ZkClient.java:990)
... 13 more
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90921 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], end rebalancing consumer abadd22221aaa1_OO_oo-1496870544934-ee22c3ca try #4
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90921 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Rebalancing attempt failed. Clearing the cache before the next rebalancing operation is triggered
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90923 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping leader finder thread
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90924 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] Stopping all fetchers
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90924 ] - [ INFO ] [ConsumerFetcherManager-1496870554044] All connections stopped
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90924 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared all relevant queues for this fetcher
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90924 ] - [ DEBUG ] Clearing the current data chunk for this consumer iterator
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90924 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Cleared the data chunks in all the consumer message iterators
2017-06-08 05:23:55 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:90924 ] - [ INFO ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], Committing all offsets after clearing the fetcher queues
2017-06-08 05:23:57 [ abadd22221aaa1_OO_oo-1496870544934-ee22c3ca_watcher_executor:92927 ] - [ ERROR ] [abadd22221aaa1_OO_oo-1496870544934-ee22c3ca], error during syncedRebalance
kafka.common.ConsumerRebalanceFailedException: abadd22221aaa1_OO_oo-1496870544934-ee22c3ca can't rebalance after 5 retries
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener.syncedRebalance(ZookeeperConsumerConnector.scala:670)
at kafka.consumer.ZookeeperConsumerConnector$ZKRebalancerListener$$anon$2.run(ZookeeperConsumerConnector.scala:589)
2017-06-08 05:23:58 [ main-SendThread():94251 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 10ms
2017-06-08 05:24:02 [ main-SendThread():97597 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 22ms
2017-06-08 05:24:05 [ main-SendThread():100919 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 10ms
2017-06-08 05:24:08 [ main-SendThread():104252 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 10ms
2017-06-08 05:24:12 [ main-SendThread():107584 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 9ms
2017-06-08 05:24:15 [ main-SendThread():110920 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 10ms
2017-06-08 05:24:18 [ main-SendThread():114253 ] - [ DEBUG ] Got ping response for sessionid: 0x1571d0f893900d4 after 9ms
> NoNodeException result in rebalance failed
> ------------------------------------------
>
> Key: KAFKA-5406
> URL: https://issues.apache.org/jira/browse/KAFKA-5406
> Project: Kafka
> Issue Type: Bug
> Components: consumer
> Affects Versions: 0.8.2.2, 0.10.0.0
> Environment: windows8.1 centos6.4
> Reporter: xiaoguy
> Priority: Critical
> Labels: easyfix, patch
> Attachments: log.log
>
>
> hey guys , I got this problem this days,
> because of the network is unstable， consumer rebalance failed after 5 times ,the log shows that zk path /consumers/$(groupIdName)/ids/ is null,
> consumer seems can't register after network recovered, so i got the kafka source code (0.8.2.2) and found the consumer/ZookeeperConsumerConnector$ZKSessionExpireListener handleNewSession won't call , and handleStateChanged do nothing,
> so i change the code like this ,and it seems works , and i checked 0.10.0.0 version, the same problem, is this a bug ? i'm confused , thank you.
> def handleStateChanged(state: KeeperState) {
> // do nothing, since zkclient will do reconnect for us.
> if(state==KeeperState.SyncConnected){
> handleNewSession()
> }
> System.err.println("----------------ZKSessionExpireListener------------ handleStateChanged-----state:"+state+"----"+state.getIntValue)
> }
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)