twmb / franz-go

franz-go contains a feature complete, pure Go library for interacting with Kafka from 0.8.0 through 3.6+. Producing, consuming, transacting, administrating, etc.
BSD 3-Clause "New" or "Revised" License
1.6k stars 158 forks source link

Broker Throttling #770

Closed jdenquin closed 2 weeks ago

jdenquin commented 2 weeks ago

Hello There,

I face some issues with one of our production consumers group that is throttled by the broker, here is the full log :

[2024-06-18 17:35:43.404] [INFO] immediate metadata update triggered; why: querying metadata for consumer initialization
[2024-06-18 17:35:43.449] [INFO] beginning to manage the group lifecycle; group: us_post_process_events_raw
[2024-06-18 17:35:43.449] [INFO] joining group; group: us_post_process_events_raw
[2024-06-18 17:35:43.493] [INFO] join returned MemberIDRequired, rejoining with response's MemberID; group: us_post_process_events_raw, member_id: kgo-400b99f3-94f7-4d56-a0ac-3e9efcae3cee
[2024-06-18 17:35:49.143] [INFO] joined, balancing group; group: us_post_process_events_raw, member_id: kgo-400b99f3-94f7-4d56-a0ac-3e9efcae3cee, instance_id: <nil>, generation: 4, balance_protocol: cooperative-sticky, leader: true
[2024-06-18 17:35:49.143] [INFO] balancing group as leader
[2024-06-18 17:35:49.143] [INFO] balance group member; id: kgo-400b99f3-94f7-4d56-a0ac-3e9efcae3cee, interests: interested topics: [events_raw], previously owned: 
[2024-06-18 17:35:49.143] [INFO] balanced; plan: kgo-400b99f3-94f7-4d56-a0ac-3e9efcae3cee{events_raw[0 1 2 3 4]}
[2024-06-18 17:35:49.143] [INFO] syncing; group: us_post_process_events_raw, protocol_type: consumer, protocol: cooperative-sticky
[2024-06-18 17:35:49.146] [INFO] synced; group: us_post_process_events_raw, assigned: events_raw[0 1 2 3 4]
[2024-06-18 17:35:49.146] [INFO] new group session begun; group: us_post_process_events_raw, added: events_raw[0 1 2 3 4], lost: 
Starting consume for topic events_raw partition 2
Starting consume for topic events_raw partition 4
Starting consume for topic events_raw partition 0
Starting consume for topic events_raw partition 3
Starting consume for topic events_raw partition 1
[2024-06-18 17:35:49.146] [INFO] beginning heartbeat loop; group: us_post_process_events_raw
[2024-06-18 17:35:49.167] [INFO] assigning partitions; why: newly fetched offsets for group us_post_process_events_raw, how: assigning everything new, keeping current assignment, input: events_raw[2{346227 e1 ce0} 3{750220 e1 ce0} 4{726504 e1 ce0} 0{39630558 e6 ce0} 1{163393 e1 ce0}]
[2024-06-18 17:35:49.167] [INFO] metadata update triggered; why: loading offsets in new session from assign
[2024-06-18 17:35:50.557] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 6, throttles_after_resp: true
[2024-06-18 17:35:50.601] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 20, throttles_after_resp: true
[2024-06-18 17:35:50.658] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 75, throttles_after_resp: true
[2024-06-18 17:35:50.77] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 97, throttles_after_resp: true
[2024-06-18 17:35:50.78] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 80, throttles_after_resp: true
[2024-06-18 17:35:50.904] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 63, throttles_after_resp: true
[2024-06-18 17:35:50.94] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 78, throttles_after_resp: true
[2024-06-18 17:35:51.005] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 5, throttles_after_resp: true
[2024-06-18 17:35:51.099] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 134, throttles_after_resp: true
[2024-06-18 17:35:51.131] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 54, throttles_after_resp: true
[2024-06-18 17:35:51.222] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 90, throttles_after_resp: true
[2024-06-18 17:35:51.312] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 97, throttles_after_resp: true
[2024-06-18 17:35:51.349] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 26, throttles_after_resp: true
[2024-06-18 17:35:51.377] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 11, throttles_after_resp: true
[2024-06-18 17:35:51.491] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 82, throttles_after_resp: true
[2024-06-18 17:35:51.51] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 31, throttles_after_resp: true
[2024-06-18 17:35:51.586] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 104, throttles_after_resp: true
[2024-06-18 17:35:51.726] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 90, throttles_after_resp: true
[2024-06-18 17:35:51.743] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 56, throttles_after_resp: true
[2024-06-18 17:35:51.878] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 54, throttles_after_resp: true
[2024-06-18 17:35:51.96] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 33, throttles_after_resp: true
[2024-06-18 17:35:51.994] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 10, throttles_after_resp: true
[2024-06-18 17:35:52.013] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 142, throttles_after_resp: true
[2024-06-18 17:35:52.122] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 117, throttles_after_resp: true
[2024-06-18 17:35:52.231] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 4, throttles_after_resp: true
[2024-06-18 17:35:52.278] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 84, throttles_after_resp: true
[2024-06-18 17:35:52.318] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 85, throttles_after_resp: true
[2024-06-18 17:35:52.4] [INFO] broker is throttling us in response; broker: 1, req: Fetch, throttle_millis: 43, throttles_after_resp: true
[2024-06-18 17:35:52.485] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 171, throttles_after_resp: true
[2024-06-18 17:35:52.738] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 161, throttles_after_resp: true
[2024-06-18 17:35:53.15] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 48, throttles_after_resp: true
[2024-06-18 17:35:53.275] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 116, throttles_after_resp: true
[2024-06-18 17:35:53.468] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 146, throttles_after_resp: true
[2024-06-18 17:35:53.691] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 37, throttles_after_resp: true
[2024-06-18 17:35:53.895] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 13, throttles_after_resp: true
[2024-06-18 17:35:53.985] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 154, throttles_after_resp: true
[2024-06-18 17:35:54.219] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 5, throttles_after_resp: true
[2024-06-18 17:35:54.299] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 78, throttles_after_resp: true
[2024-06-18 17:35:54.454] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 206, throttles_after_resp: true
[2024-06-18 17:35:54.702] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 43, throttles_after_resp: true
[2024-06-18 17:35:54.787] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 10, throttles_after_resp: true
[2024-06-18 17:35:54.928] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 99, throttles_after_resp: true
[2024-06-18 17:35:55.069] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 58, throttles_after_resp: true
[2024-06-18 17:35:55.168] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 28, throttles_after_resp: true
[2024-06-18 17:35:55.28] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 16, throttles_after_resp: true
[2024-06-18 17:35:55.337] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 51, throttles_after_resp: true
[2024-06-18 17:35:55.428] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 73, throttles_after_resp: true
[2024-06-18 17:35:55.543] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 60, throttles_after_resp: true
[2024-06-18 17:35:55.643] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 25, throttles_after_resp: true
[2024-06-18 17:35:55.708] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 2, throttles_after_resp: true
[2024-06-18 17:35:55.752] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 3, throttles_after_resp: true
[2024-06-18 17:35:55.797] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 48, throttles_after_resp: true
[2024-06-18 17:35:55.886] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 81, throttles_after_resp: true
[2024-06-18 17:35:56.008] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 69, throttles_after_resp: true
[2024-06-18 17:35:56.108] [INFO] broker is throttling us in response; broker: 0, req: Fetch, throttle_millis: 23, throttles_after_resp: true

It seems that the consumers stay opened but the broker never send us data. Should I adapt my kgo configuration to handle it?