Broker outage sent controller into infinite loop

[Karolis Pocius <k....@adform.com>]

I'm managing a 21 node Kafka cluster, running 0.8.2.1. Recently one 
broker crashed during software RAID rebuild after one of the OS disks 
failed (Kafka logs are stored on separate RAID1+0 drive).

At first the controller behaved as expected, marking the node as down 
and sending out messages to remaining brokers:

[2016-11-04 15:45:03,130] INFO [Controller 20]: Shutting down broker 11 
(kafka.controller.KafkaController)
[2016-11-04 15:45:03,134] DEBUG [Controller 20]: All shutting down 
brokers: 11 (kafka.controller.KafkaController)
[2016-11-04 15:45:03,134] DEBUG [Controller 20]: Live brokers: 
5,10,14,20,1,6,21,9,13,2,17,22,12,7,3,18,16,8,4,15 
(kafka.controller.KafkaController)
[2016-11-04 15:45:03,147] DEBUG [Controller 20]: Removing replica 11 
from ISR 5,11,12 for partition [topic_xx,3]. 
(kafka.controller.KafkaController)

The last line was repeated for each partition on the failed broker until 
it reached __consumer_offsets,39:

[2016-11-04 15:45:03,447] DEBUG [Controller 20]: Removing replica 11 
from ISR 12,16,11 for partition [__consumer_offsets,39]. 
(kafka.controller.KafkaController)
[2016-11-04 15:45:03,450] INFO [Controller 20]: New leader and ISR for 
partition [__consumer_offsets,39] is 
{"leader":16,"leader_epoch":258,"isr":[12,16]} 
(kafka.controller.KafkaController)
[2016-11-04 15:45:03,451] DEBUG The stop replica request (delete = true) 
sent to broker 11 is (kafka.controller.ControllerBrokerRequestBatch)
[2016-11-04 15:45:03,451] DEBUG The stop replica request (delete = 
false) sent to broker 11 is 
[Topic=__consumer_offsets,Partition=39,Replica=11] 
(kafka.controller.ControllerBrokerRequestBatch)

After which (12 seconds later) broker change listener fired:

[2016-11-04 15:45:15,008] INFO [BrokerChangeListener on Controller 20]: 
Broker change listener fired for path /brokers/ids with children 
22,17,18,15,16,13,14,12,21,3,2,20,1,10,7,6,5,4,9,8 
(kafka.controller.ReplicaStateMachine$BrokerChangeListener)

And then the logs just kept looping this:

[2016-11-04 15:45:33,780] WARN [Controller-20-to-broker-11-send-thread], 
Controller 20 epoch 103 fails to send request Name: StopReplicaRequest; 
Version: 0; CorrelationId: 8831; ClientId: ; DeletePartitions: false; 
ControllerId: 20; ControllerEpoch: 103; Partitions: 
[__consumer_offsets,39] to broker id:11,host:10.0.12.41,port:9092. 
Reconnecting to broker. (kafka.controller.RequestSendThread)
[2016-11-04 15:46:03,810] INFO [Controller-20-to-broker-11-send-thread], 
Controller 20 connected to id:11,host:10.0.12.41,port:9092 for sending 
state change requests (kafka.controller.RequestSendThread)

While it was happening, most producers were still trying to reach the 
failed node and throwing an I/O error. An hour later, after restarting 
the controller everything went back to normal.

I searched for known issues and this seems to be the closest to what 
happened https://issues.apache.org/jira/browse/KAFKA-2125 but it's 
marked as "Resolved" and not quite clear what was fixed and where. It 
mentions connection quotas, but each broker has max.connections.per.ip 
set to 1000, so it's not likely that this limit was reached and 
monitoring tools do not show any abnormal growth in connections 
following the initial broker crash.

Also, what I find strange is that logs seem to indicate controller 
managed to connect to the dead broker each time, but then timed out. I 
know for a fact that broker was unreachable, so either the log message 
is worded incorrectly, or it was in fact connecting to something else.

Any ideas as to what happened here or where to look for more clues?