rebalance time at startup

[vkanduveed]

Hello,

I have an application that has consumer group(s) with one consumer instance reading off different topic(s) with one partition.
When the application restarts, it takes about 40 seconds for consumer_poll() to come out with a message.

Kafka logs say that it took 40 seconds to go from 'preparing rebalance' to being a 'stable group'. My question is why does it take 40 seconds to rebalance although there was only consumer instance before and after the restart.

I tried to enable static membership for the consumer instance - but i still see the 40 second delay at startup.

Why is it taking 40 seconds to rebalance a group ? Is there a way to avoid the 40 second delay ?

Vasudev

This is the snippet from the kafka logs :

[2022-01-22 01:16:05,858] INFO [GroupCoordinator 0]: Preparing to rebalance group pd-dme-envoy-placement with old generation 13 (__consumer_offsets-5) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:05,883] INFO [GroupCoordinator 0]: Preparing to rebalance group pd-dme-envoy-config with old generation 14 (__consumer_offsets-26) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:05,939] INFO [GroupCoordinator 0]: Preparing to rebalance group pd-dme-envoy-metrics with old generation 3 (__consumer_offsets-13) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:06,030] INFO [GroupCoordinator 0]: Preparing to rebalance group pd-dme-envoy-sv-config with old generation 15 (__consumer_offsets-44) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:16,769] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:222}, Current: {epoch:527, offset211} for Partition: environment-updates-0. Cache now contains 4 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:19,722] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:13885}, Current: {epoch:527, offset13884} for Partition: kms-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:20,185] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:13885}, Current: {epoch:527, offset13884} for Partition: cloud-sv-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:20,207] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:2107}, Current: {epoch:527, offset1847} for Partition: __consumer_offsets-18. Cache now contains 20 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:22,684] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:13884}, Current: {epoch:527, offset13883} for Partition: site-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:23,951] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:15865}, Current: {epoch:527, offset15864} for Partition: di-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:25,674] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:14079}, Current: {epoch:527, offset14078} for Partition: share-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:25,864] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:79445}, Current: {epoch:527, offset79434} for Partition: ds-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:28,402] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:13961}, Current: {epoch:527, offset13960} for Partition: slo-config-0. Cache now contains 7 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:34,831] INFO [GroupCoordinator 0]: Preparing to rebalance group cm-1e4c97cd-e899-42e5-9a68-4061c59f17ff-csp-info-group with old generation 24 (__consumer_offsets-4) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:41,572] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:48517005}, Current: {epoch:527, offset48514930} for Partition: __consumer_offsets-40. Cache now contains 513 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:41,580] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:48519645}, Current: {epoch:527, offset48517574} for Partition: __consumer_offsets-14. Cache now contains 513 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:41,646] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:48335696}, Current: {epoch:527, offset48333624} for Partition: __consumer_offsets-7. Cache now contains 513 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:41,687] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:48520586}, Current: {epoch:527, offset48518515} for Partition: __consumer_offsets-30. Cache now contains 513 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:41,816] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:48497472}, Current: {epoch:527, offset48495400} for Partition: __consumer_offsets-16. Cache now contains 513 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:41,911] INFO Updated PartitionLeaderEpoch. New: {epoch:528, offset:48518291}, Current: {epoch:527, offset48516219} for Partition: __consumer_offsets-46. Cache now contains 513 entries. (kafka.server.epoch.LeaderEpochFileCache)
[2022-01-22 01:16:44,701] INFO [GroupCoordinator 0]: Member envoy-client-aa5a08ca-4209-4d51-9597-7dd0fa5d0b1f in group pd-dme-envoy-placement has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:44,701] INFO [GroupCoordinator 0]: Stabilized group pd-dme-envoy-placement generation 14 (__consumer_offsets-5) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:44,703] INFO [GroupCoordinator 0]: Assignment received from leader for group pd-dme-envoy-placement for generation 14 (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:46,411] INFO [GroupCoordinator 0]: Member envoy-client-86c14f9e-4857-44dd-9cd2-16291d33da70 in group pd-dme-envoy-sv-config has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:46,412] INFO [GroupCoordinator 0]: Stabilized group pd-dme-envoy-sv-config generation 16 (__consumer_offsets-44) (kafka.coordinator.group.GroupCoordinator)
[2022-01-22 01:16:46,412] INFO [GroupCoordinator 0]: Member envoy-client-b1fb0a5c-6e2d-4167-b3b6-9f6a3dc0e27e in group pd-dme-envoy-metrics has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator)