[
https://issues.apache.org/jira/browse/KAFKA-21316?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18129062#comment-18129062
]
ILKYUN LIM commented on KAFKA-21316:
------------------------------------
h3. Additional test results
h4. Reproduction on test clusters
Setup: three test clusters (follower heap 1 GiB, 2 GiB and 6 GiB, G1, JDK 21).
Two topics were picked so that their partitions are fetched by the same fetcher
thread (abs(31 * topic.hashCode() + partition) % num.replica.fetchers) and land
in the same bucket of that fetcher's map. Consecutive partitions of one topic
rarely share a bucket, so this needs to be computed. Each partition of the pair
received about 1,000 records/s.
Measurement: trigger a full GC on the follower so that live entries are
promoted, wait 10 minutes, take a heap dump, and count the longest chain of
removed LinkedHashMap$Entry objects linked through next.
||Heap||Original PartitionStates (runs)||With the fix (runs)||
|1 GiB|339,594 / 5,855 / 8,256 / 838|2 / 2 / 3 / 2|
|2 GiB|7,713 / 309,597|3 / 3|
|6 GiB|2,820 / 2,868|4 / 4|
The original code reproduced the chain in every run; one promotion is enough,
whatever causes it. With the fix the longest chain stayed at 2-4 in every run,
which is just the garbage between two young GCs. As a control, the original
code without a same-bucket pair gave 34.
h4. When it gets bad
The cluster where we hit it has many partitions with small, continuous writes,
so followers fetch very often (about 4,500 follower fetches/s per broker) and
the chain grows quickly. On that 18-broker cluster, 7 brokers had at least one
same-bucket pair with continuous writes. Removed entries are only created when
a fetch returns data (validBytes > 0), so idle partitions do not contribute.
h4. Regression testing
* clients unit tests (13,134), consumer integration tests (375) and core
kafka.server.* tests (1,998) on 4.3.1 with the patch. Two failures
(KafkaProducerTest.negativePartitionShouldThrow,
PlaintextConsumerTest.testAsyncConsumerEndOffsets) passed when re-run three
times each; the second also passes on the original code.
* Our end-to-end suite on a 3-broker cluster passed: produce/consume, broker
restart, broker kill, controller restart, quota throttling, authentication
paths, broker failure, in-place upgrade and scale-out.
h4. Production
The patch has been running in production on the cluster where we hit the issue
(18 brokers, 16 GiB heap) since October 19, with no recurrence. The slowdown
used to start about 7.5 hours after a restart; since the rollout no broker has
gone above 15 ms average young GC pause in any hour, including today under
about 1 GiB/s of new inbound traffic and 4-6 GiB/s outbound.
||||Same 19-hour window, day before||After the rollout||
|Young GC time (18 brokers, per hour)|49.5 s|22.1 s|
|Highest per-broker 1-hour average young GC pause|35.8 ms|12.1 ms|
|Survivor regions dropping to 0 / full GC|-|0 / 0|
The same rollout also included an unrelated change that reduced heap pressure
from large buffers in a tiered storage plugin, so these production numbers are
for both changes together; the test runs above isolate this patch.
> Removed entries in PartitionStates stay chained and slow down young GC on
> follower brokers
> ------------------------------------------------------------------------------------------
>
> Key: KAFKA-21316
> URL: https://issues.apache.org/jira/browse/KAFKA-21316
> Project: Kafka
> Issue Type: Bug
> Components: clients, replication
> Affects Versions: 4.3.1
> Reporter: ILKYUN LIM
> Assignee: ILKYUN LIM
> Priority: Major
> Labels: performance
>
> h3. Problem
> {{PartitionStates}} keeps its order in a {{LinkedHashMap}} and moves a
> partition to the end with {{remove}} + {{put}} ({{updateAndMoveToEnd}}).
> {{HashMap.removeNode}} does not clear the {{next}} field of the removed entry
> (same in JDK 17, 21 and 25). When two partitions whose keys fall into the
> same bucket are updated in turn, every removed entry keeps pointing at the
> entry created after it, so the removed entries form one chain.
> Once one entry of that chain is promoted to the old generation, every young
> GC treats the chain as live and copies all removed entries that follow it.
> The chain keeps growing as long as both partitions receive data. Because it
> is a linked list, a single GC worker copies it entry by entry, so pauses grow
> while the copied bytes stay small.
> The only condition is two partitions that keep receiving data, fetched by the
> same fetcher thread, whose keys fall into the same bucket of that fetcher's
> map. The remove + put pattern has been there since KIP-74.
> h3. Observed
> Follower broker, Kafka 4.3.1, JDK 21, G1, 16 GiB heap,
> {{MaxGCPauseMillis=20}}:
> * A mixed GC ran out of free regions ({{Survivor regions: 1->0(0)}}) and
> promoted the replica fetcher's map entries.
> * Young GC pauses went from 11 ms to 34 ms on average (single pauses 30-50
> ms) and stayed there until the broker was restarted. G1 then shrank Eden to
> keep up with the pause goal, which made young GCs about 6 times more frequent.
> * A heap dump taken about 14 hours after the onset held 2,048,712 removed
> {{LinkedHashMap$Entry}} objects linked through {{next}}, alternating between
> the two partitions of one bucket of one fetcher's map.
> Reproduction without a broker: updating two such partitions in turn one
> million times leaves 2,000,002 entries reachable from the first removed entry.
> h3. Fix
> Pull request: https://github.com/apache/kafka/pull/23839
> Keep the order in a doubly linked list of nodes looked up through a
> {{HashMap}}, and move the existing node to the end instead of creating a new
> one. This matches what the leader side already does for fetch sessions with
> {{ImplicitLinkedHashCollection}}. {{LinkedHashMap.putLast}} would do the same
> in one call but needs Java 21, and the clients module still targets Java 11.
> Order, {{partitionStateMap()}} (a live unmodifiable view) and {{size()}}
> behave as before. {{stateIterator().remove()}} is no longer supported; no
> caller uses it, and with the old code it left {{size()}} stale.
> A new JMH benchmark ({{PartitionStatesBenchmark}}, JDK 21) shows
> {{updateAndMoveToEnd}} going from 11.6-13.3 ns and 40 B/op to 5.5-8.6 ns and
> 0 B/op. {{ReplicaFetcherThreadBenchmark}} is faster at 100-1000 partitions
> and within the error at 5000.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
