I have done perf testing for this PR and here are the results: **1. Controller fails over** Trunk (`bf0675`) - run 1 ``` [2018-09-01 00:47:20,564] INFO [Controller id=1495] 1495 successfully elected as the controller (kafka.controller.KafkaController) [2018-09-01 00:47:27,938] INFO [Controller id=1495] Starting the controller scheduler (kafka.controller.KafkaController) ``` Trunk (`bf0675`) - run 2 ``` [2018-09-01 00:54:44,615] INFO [Controller id=1496] 1496 successfully elected as the controller (kafka.controller.KafkaController) [2018-09-01 00:54:59,529] INFO [Controller id=1496] Starting the controller scheduler (kafka.controller.KafkaController) ```
KAFKA-6082 - run 1 ``` [2018-09-01 00:23:45,949] INFO [Controller id=1495] 1495 successfully elected as the controller. Epoch incremented to 9 and epoch zk version is now 9 (kafka.controller.KafkaController) [2018-09-01 00:23:53,251] INFO [Controller id=1495] Starting the controller scheduler (kafka.controller.KafkaController) ``` KAFKA-6082 - run 2 ``` [2018-09-01 00:29:08,524] INFO [Controller id=1494] 1494 successfully elected as the controller. Epoch incremented to 10 and epoch zk version is now 10 (kafka.controller.KafkaController) [2018-09-01 00:29:19,121] INFO [Controller id=1494] Starting the controller scheduler (kafka.controller.KafkaController) ``` Trunk avg = ~6s KAFKA-6082 avg = ~9s **2. Preferred replica leader election** Trunk (`bf0675`) - ~2.4k leadership movements ``` [2018-09-03 23:25:12,201] INFO [Controller id=1497] Starting preferred replica leader election for partitions [2018-09-03 23:25:12,692] INFO [Controller id=1497] Partition 10-1149-0 completed preferred replica leader election. New leader is 1496 (kafka.controller.KafkaController) ``` KAFKA-6082 - ~2.4k leadership movements ``` [2018-09-04 04:35:25,592] INFO [Controller id=1497] Starting preferred replica leader election for partitions ... [2018-09-04 04:35:26,136] INFO [Controller id=1497] Partition 7-1801-0 completed preferred replica leader election. New leader is 1495 (kafka.controller.KafkaController ``` Trunk = 491ms KAFKA-6082 = 544ms Trunk (`bf0675`) - ~4.8k leadership movements ``` [2018-09-03 23:25:09,378] INFO [Controller id=1497] Starting preferred replica leader election for partitions ... ... [2018-09-03 23:25:10,482] INFO [Controller id=1497] Partition 8-1915-0 completed preferred replica leader election. New leader is 1497 (kafka.controller.KafkaController) ``` KAFKA-6082 - broker 1497 (~4.8k leader) ``` [2018-09-04 04:35:22,313] TRACE [Controller id=1497] Starting preferred replica leader election for partitions ... [2018-09-04 04:35:23,397] INFO [Controller id=1497] Partition 8-1915-0 completed preferred replica leader election. New leader is 1497 (kafka.controller.KafkaController) ``` Trunk = 1.104s KAFKA-6082 = 1.084s Trunk (`bf0675`) - ~6k leadership movements ``` [2018-09-03 23:25:10,521] INFO [Controller id=1497] Starting preferred replica leader election for partitions ... ... [2018-09-03 23:25:11,860] INFO [Controller id=1497] Partition 5-1613-2 completed preferred replica leader election. New leader is 1494 (kafka.controller.KafkaController) ``` KAFKA-6082 - broker 1494 (~6k leadership movements) ``` [2018-09-04 04:35:23,431] INFO [Controller id=1497] Starting preferred replica leader election for ... [2018-09-04 04:35:24,583] INFO [Controller id=1497] Partition 5-1613-2 completed preferred replica leader election. New leader is 1494 (kafka.controller.KafkaController) ``` Trunk = 1.339s KAFKA-6082 = 1.152s **3. Controlled shutdown** Trunk (`bf0675`) - run 1 ``` [2018-09-04 00:05:28,098] INFO [Controller id=1497] Shutting down broker 1495 (kafka.controller.KafkaController) [2018-09-04 00:05:31,773] TRACE [Controller id=1497] All leaders = ... ``` Trunk (`bf0675`) - run 2 ``` [2018-09-04 04:15:05,235] INFO [Controller id=1494] Shutting down broker 1496 (kafka.controller.KafkaController) [2018-09-04 04:15:08,823] TRACE [Controller id=1494] All leaders = ... ``` KAFKA-6082 - run 1 ``` [2018-09-04 04:51:10,175] INFO [Controller id=1497] Shutting down broker 1495 (kafka.controller.KafkaController) [2018-09-04 04:51:13,825] TRACE [Controller id=1497] All leaders ... ``` KAFKA-6082 - run 2 ``` [2018-09-04 05:11:32,197] INFO [Controller id=1497] Shutting down broker 1496 (kafka.controller.KafkaController) [2018-09-04 05:11:35,846] TRACE [Controller id=1497] All leaders ... ``` Trunk avg = 3.63s KAFKA-6082 avg = 3.65s **4. Broker start** Trunk (`bf0675`) - run 1 ``` [2018-09-04 04:19:20,353] INFO [Controller id=1494] Newly added brokers: 1496, deleted brokers: , all live brokers: 1493,1494,1495,1496,1497 (kafka.controller.KafkaController) [2018-09-04 04:19:25,233] DEBUG [Controller id=1494] Register BrokerModifications handler for ArrayBuffer(1496) (kafka.controller.KafkaController) ``` Trunk (`bf0675`) - run 2 ``` [2018-09-04 00:09:49,320] INFO [Controller id=1497] Newly added brokers: 1495, deleted brokers: , all live brokers: 1493,1494,1495,1496,1497 (kafka.controller.KafkaController) [2018-09-04 00:09:53,772] DEBUG [Controller id=1497] Register BrokerModifications handler for ArrayBuffer(1495) (kafka.controller.KafkaController) ``` KAFKA-6082 - run 1 ``` [2018-09-04 04:53:49,998] INFO [Controller id=1497] Newly added brokers: 1495, deleted brokers: , all live brokers: 1493,1494,1495,1496,1497 (kafka.controller.KafkaController) [2018-09-04 04:53:52,314] DEBUG [Controller id=1497] Register BrokerModifications handler for ArrayBuffer(1495) (kafka.controller.KafkaController) ``` KAFKA-6082 - run 2 ``` [2018-09-04 05:13:23,159] INFO [Controller id=1497] Newly added brokers: 1496, deleted brokers: , all live brokers: 1493,1494,1495,1496,1497 (kafka.controller.KafkaController) [2018-09-04 05:13:25,254] DEBUG [Controller id=1497] Register BrokerModifications handler for ArrayBuffer(1496) (kafka.controller.KafkaController) ``` Trunk avg = 4.67s KAFKA-6082 avg = 2.21s [ Full content available at: https://github.com/apache/kafka/pull/5101 ] This message was relayed via gitbox.apache.org for [email protected]
