thanks for your reply. yes, there are more than one controller. the msg of "soft failure" is reported by the old controller.
2016-05-31 11:42 GMT+08:00 Muqtafi Akhmad <muqt...@traveloka.com>: > hello Fredo, > > My guess is that there was partition leader election that was might be > triggered by detection of offline partition in Kafka cluster. Somehow the > broker try to trigger leader election while previous election has been > completed hence this log : > > > [2016-05-28 12:33:31,511] ERROR Controller 1008 epoch 13 initiated state > > change for partition [consup-0000000043,78] from OnlinePartition to > > OnlinePartition failed (state.change.logger) > > kafka.common.StateChangeFailedException: encountered error while electing > > leader for partition [consup-0000000043,78] due to: aborted leader > election > > for partition [consup-0000000043,78] > > since the LeaderAndIsr path was already written by another controller. > This > > probably means that the current controller 1008 went through a soft > failure > > and another controller was elec > > ted with epoch 14.. > > The question is, > - was there any offline partition? > - was there more than one active controller? > > CMIIW > > > On Mon, May 30, 2016 at 2:41 PM, Fredo Lee <buaatianwa...@gmail.com> > wrote: > > > my server.log >>>>>>>>>>>>>>>> > > > > lots of error msg: > > > > [2016-05-28 12:12:31,132] WARN [ReplicaFetcherThread-0-1007], Replica > 1008 > > for partition [consup-0000000003,16] reset its fetch offset from 13985537 > > to current leader 1007's latest offset 13985537 > > (kafka.server.ReplicaFetcherThread) > > [2016-05-28 12:12:31,132] ERROR [ReplicaFetcherThread-0-1007], Current > > offset 13987676 for partition [consup-0000000003,16] out of range; reset > > offset to 13985537 (kafka.server.ReplicaFetcherThread) > > > > > > the other error msg: > > > > [2016-05-28 12:12:31,708] ERROR [Replica Manager on Broker 1008]: Error > > when processing fetch request for partition [consup-0000000003,35] offset > > 13848954 from consumer with correlation id 0. Possible cause: Request for > > offset 13848954 but we only have log segments in the range 12356946 to > > 13847167. (kafka.server.ReplicaManager) > > > > > > > > 2016-05-30 15:37 GMT+08:00 Fredo Lee <buaatianwa...@gmail.com>: > > > > > My state-change.log>>>>>>>>>>> > > > > > > > > > [2016-05-28 12:33:31,510] ERROR Controller 1008 epoch 13 aborted leader > > > election for partition [consup-0000000043,78] since the LeaderAndIsr > path > > > was already written by another controll > > > er. This probably means that the current controller 1008 went through a > > > soft failure and another controller was elected with epoch 14. > > > (state.change.logger) > > > [2016-05-28 12:33:31,510] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(1020,-1) for a request sent to broker > > id:1009,host: > > > 22.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,510] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(1066,-1) for a request sent to broker > > id:1001,host: > > > consup-kafka20.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,510] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(777,-1) for a request sent to broker > id:1006,host: > > > consup-kafka11.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,510] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(742,-1) for a request sent to broker > id:1018,host: > > > consup-kafka10.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,510] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(1021,-1) for a request sent to broker > > id:1009,host: > > > consup-kafka22.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,511] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(1067,-1) for a request sent to broker > > id:1001,host: > > > consup-kafka20.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,511] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(778,-1) for a request sent to broker > id:1006,host: > > > consup-kafka11.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,511] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(1022,-1) for a request sent to broker > > id:1009,host: > > > consup-kafka22.com,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,511] ERROR Controller 1008 epoch 13 encountered > > error > > > while electing leader for partition [consup-0000000043,78] due to: > > aborted > > > leader election for partition [consup > > > -0000000043,78] since the LeaderAndIsr path was already written by > > another > > > controller. This probably means that the current controller 1008 went > > > through a soft failure and another con > > > troller was elected with epoch 14.. (state.change.logger) > > > [2016-05-28 12:33:31,511] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(743,-1) for a request sent to broker > id:1018,host: > > > consup-kafka10.co > > > m,port:9092 (state.change.logger) > > > [2016-05-28 12:33:31,511] ERROR Controller 1008 epoch 13 initiated > state > > > change for partition [consup-0000000043,78] from OnlinePartition to > > > OnlinePartition failed (state.change.logger) > > > kafka.common.StateChangeFailedException: encountered error while > electing > > > leader for partition [consup-0000000043,78] due to: aborted leader > > election > > > for partition [consup-0000000043,78] > > > since the LeaderAndIsr path was already written by another controller. > > > This probably means that the current controller 1008 went through a > soft > > > failure and another controller was elec > > > ted with epoch 14.. > > > at > > > > > > kafka.controller.PartitionStateMachine.electLeaderForPartition(PartitionStateMachine.scala:380) > > > at > > > > > > kafka.controller.PartitionStateMachine.kafka$controller$PartitionStateMachine$$handleStateChange(PartitionStateMachine.scala:208) > > > at > > > > > > kafka.controller.PartitionStateMachine$$anonfun$handleStateChanges$2.apply(PartitionStateMachine.scala:146) > > > at > > > > > > kafka.controller.PartitionStateMachine$$anonfun$handleStateChanges$2.apply(PartitionStateMachine.scala:145) > > > at scala.collection.immutable.Set$Set1.foreach(Set.scala:79) > > > at > > > > > > kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:145) > > > at > > > > > > kafka.controller.KafkaController.onPreferredReplicaElection(KafkaController.scala:631) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4$$anonfun$apply$17$$anonfun$apply$5.apply$mcV$sp(KafkaControl > > > ler.scala:1158) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4$$anonfun$apply$17$$anonfun$apply$5.apply(KafkaController.sca > > > la:1153) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4$$anonfun$apply$17$$anonfun$apply$5.apply(KafkaController.sca > > > la:1153) > > > at kafka.utils.Utils$.inLock(Utils.scala:535) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4$$anonfun$apply$17.apply(KafkaController.scala:1150) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4$$anonfun$apply$17.apply(KafkaController.scala:1148) > > > at > > > > > > scala.collection.mutable.HashMap$$anonfun$foreach$1.apply(HashMap.scala:99) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4.apply(KafkaController.scala:1148) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance$4.apply(KafkaController.scala:1127) > > > at > > > scala.collection.immutable.HashMap$HashMap1.foreach(HashMap.scala:221) > > > at > > > > scala.collection.immutable.HashMap$HashTrieMap.foreach(HashMap.scala:428) > > > at > > > > > > kafka.controller.KafkaController.kafka$controller$KafkaController$$checkAndTriggerPartitionRebalance(KafkaController.scala:1127) > > > at > > > > > > kafka.controller.KafkaController$$anonfun$onControllerFailover$1.apply$mcV$sp(KafkaController.scala:326) > > > at > > > > > > kafka.utils.KafkaScheduler$$anonfun$1.apply$mcV$sp(KafkaScheduler.scala:99) > > > at kafka.utils.Utils$$anon$1.run(Utils.scala:54) > > > at > > > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > > > at > > > > > > java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351) > > > at > > java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178) > > > at > > > > > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165) > > > at > > > > > > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267) > > > at > > > > > > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > > > at > > > > > > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > > > at java.lang.Thread.run(Thread.java:679) > > > Caused by: kafka.common.StateChangeFailedException: aborted leader > > > election for partition [consup-0000000043,78] since the LeaderAndIsr > path > > > was already written by another controller. This probably means that the > > > current controller 1008 went through a soft failure and another > > controller > > > was elected with epoch 14. > > > at > > > > > > kafka.controller.PartitionStateMachine.electLeaderForPartition(PartitionStateMachine.scala:354) > > > ... 33 more > > > [2016-05-28 12:33:31,511] TRACE Controller 1008 epoch 13 received > > response > > > UpdateMetadataResponse(744,-1) for a request sent to broker > id:1018,host: > > > consup-kafka10.com,port:9092 (state.change.logger) > > > > > > > > > 2016-05-28 15:31 GMT+08:00 Muqtafi Akhmad <muqt...@traveloka.com>: > > > > > >> hello Fredo, > > >> > > >> Can you elaborate the 'soft' failure? > > >> > > >> > > >> > > >> On Sat, May 28, 2016 at 1:53 PM, Fredo Lee <buaatianwa...@gmail.com> > > >> wrote: > > >> > > >> > we have a kafka cluster with 19 nodes. every week we suffer a soft > > >> failure > > >> > from this cluster. how to resolve this problem. > > >> > > > >> > > >> > > >> > > >> -- > > >> Muqtafi Akhmad > > >> Software Engineer > > >> Traveloka > > >> > > > > > > > > > > > > -- > Muqtafi Akhmad > Software Engineer > Traveloka >
