[jira] [Commented] (KAFKA-9963) High CPU during replication of replaced (empty) broker
[
https://issues.apache.org/jira/browse/KAFKA-9963?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17105606#comment-17105606
]
Ishwor Gurung commented on KAFKA-9963:
--
[~blodsbror] Just out of curiosity, what was the issue?
> High CPU during replication of replaced (empty) broker
> --
>
> Key: KAFKA-9963
> URL: https://issues.apache.org/jira/browse/KAFKA-9963
> Project: Kafka
> Issue Type: Bug
> Components: core
>Affects Versions: 2.4.1
>Reporter: Evan Williams
>Priority: Major
>
> When replacing a broker, with an empty data dir, and the same broker ID - we
> are seeing very high CPU usage during replication, generally up to 100% for
> some time, on a 4 VCPU (EC2 R5) host. This is a 6 host cluster, with approx
> 1000 topics and 3000 partitions.
>
> There is of course traffic being served as well, as it catches up and becomes
> leader of partitions, however due to the high replication CPU usage -
> client's start to have connection issue. Normal traffic on this host is is
> around 40% CPU, when it's completely replicated. I'm not sure if this is
> 'normal', and we just need to throw more resources at the hosts. Or if
> replication should not really use this much CPU.
> replica.fetchers=2 (not high). And java version is: OpenJDK Runtime
> Environment Corretto-8.252.09.1 (build 1.8.0_252-b09) (AWS's own build).
> CPU profiling (2 minutes ) during this 'replace' scenario, shows this:
>
> {code:java}
> 5473000 19.43% 5473
> java.util.TreeMap$PrivateEntryIterator.nextEntry
> 4975000 17.66% 4975
> scala.collection.convert.Wrappers$JIteratorWrapper.hasNext
> 4417000 15.68% 4417 java.util.TreeMap.successor
> 17730006.29% 1773 java.util.TreeMap$ValueIterator.next
> 1706.03% 1700 java.util.TreeMap$PrivateEntryIterator.hasNext
> 6010002.13% 601
> scala.collection.convert.Wrappers$JIteratorWrapper.next
> 5160001.83% 516 writev
> --- 3885000 ns (13.79%), 3885 samples
> [ 0] java.util.TreeMap$PrivateEntryIterator.nextEntry
> [ 1] java.util.TreeMap$ValueIterator.next
> [ 2] scala.collection.convert.Wrappers$JIteratorWrapper.next
> [ 3] scala.collection.Iterator.find
> [ 4] scala.collection.Iterator.find$
> [ 5] scala.collection.AbstractIterator.find
> [ 6] scala.collection.IterableLike.find
> [ 7] scala.collection.IterableLike.find$
> [ 8] scala.collection.AbstractIterable.find
> [ 9] kafka.log.ProducerStateManager.lastStableOffset
> [10] kafka.log.Log.$anonfun$append$12
> [11] kafka.log.Log.$anonfun$append$2
> [12] kafka.log.Log.append
> [13] kafka.log.Log.appendAsFollower
> [14]
> kafka.cluster.Partition.$anonfun$doAppendRecordsToFollowerOrFutureReplica$1
> [15] kafka.cluster.Partition.doAppendRecordsToFollowerOrFutureReplica
> [16] kafka.cluster.Partition.appendRecordsToFollowerOrFutureReplica
> [17] kafka.server.ReplicaFetcherThread.processPartitionData
> [18] kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$7
> [19] kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$6
> [20]
> kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$6$adapted
> [21] kafka.server.AbstractFetcherThread$$Lambda$552.191789933.apply
> [22] scala.collection.mutable.ResizableArray.foreach
> [23] scala.collection.mutable.ResizableArray.foreach$
> [24] scala.collection.mutable.ArrayBuffer.foreach
> [25] kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$5
> [26] kafka.server.AbstractFetcherThread.processFetchRequest
> [27] kafka.server.AbstractFetcherThread.$anonfun$maybeFetch$3
> [28] kafka.server.AbstractFetcherThread.maybeFetch
> [29] kafka.server.AbstractFetcherThread.doWork
> [30] kafka.utils.ShutdownableThread.run
>
> {code}
> {code:java}
> --- 3632000 ns (12.89%), 3632 samples
> [ 0] scala.collection.convert.Wrappers$JIteratorWrapper.hasNext
> [ 1] scala.collection.Iterator.find
> [ 2] scala.collection.Iterator.find$
> [ 3] scala.collection.AbstractIterator.find
> [ 4] scala.collection.IterableLike.find
> [ 5] scala.collection.IterableLike.find$
> [ 6] scala.collection.AbstractIterable.find
> [ 7] kafka.log.ProducerStateManager.lastStableOffset
> [ 8] kafka.log.Log.$anonfun$append$12
> [ 9] kafka.log.Log.$anonfun$append$2
> [10] kafka.log.Log.append
> [11] kafka.log.Log.appendAsFollower
> [12]
> kafka.cluster.Partition.$anonfun$doAppendRecordsToFollowerOrFutureReplica$1
> [13] kafka.cluster.Partition.doAppendRecordsToFollowerOrFutureReplica
> [14] kafka.cluster.Partition.appendRecordsToFollowerOrFutureReplica
> [15] kafka.server.ReplicaFetcherThread.processPartitionData
> [16] kafka.server.AbstractFetcherThread.$anonfun$processFetchReque
[jira] [Commented] (KAFKA-9963) High CPU during replication of replaced (empty) broker
[
https://issues.apache.org/jira/browse/KAFKA-9963?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17105612#comment-17105612
]
Evan Williams commented on KAFKA-9963:
--
[~ishworgurung] Essentially on a 4vcpu (EC2 R5) instance, we have always had
num.network.threads and num.io.threads left as default. (3 and 8). However I
just changed them both to 3 (ie one less than we have cores), and we managed to
never go past 80% CPU. And it seems that the avg idle network/io threads werent
depleted either. So, it's perhaps kind of an obvious solution (or workaround).
> High CPU during replication of replaced (empty) broker
> --
>
> Key: KAFKA-9963
> URL: https://issues.apache.org/jira/browse/KAFKA-9963
> Project: Kafka
> Issue Type: Bug
> Components: core
>Affects Versions: 2.4.1
>Reporter: Evan Williams
>Priority: Major
>
> When replacing a broker, with an empty data dir, and the same broker ID - we
> are seeing very high CPU usage during replication, generally up to 100% for
> some time, on a 4 VCPU (EC2 R5) host. This is a 6 host cluster, with approx
> 1000 topics and 3000 partitions.
>
> There is of course traffic being served as well, as it catches up and becomes
> leader of partitions, however due to the high replication CPU usage -
> client's start to have connection issue. Normal traffic on this host is is
> around 40% CPU, when it's completely replicated. I'm not sure if this is
> 'normal', and we just need to throw more resources at the hosts. Or if
> replication should not really use this much CPU.
> replica.fetchers=2 (not high). And java version is: OpenJDK Runtime
> Environment Corretto-8.252.09.1 (build 1.8.0_252-b09) (AWS's own build).
> CPU profiling (2 minutes ) during this 'replace' scenario, shows this:
>
> {code:java}
> 5473000 19.43% 5473
> java.util.TreeMap$PrivateEntryIterator.nextEntry
> 4975000 17.66% 4975
> scala.collection.convert.Wrappers$JIteratorWrapper.hasNext
> 4417000 15.68% 4417 java.util.TreeMap.successor
> 17730006.29% 1773 java.util.TreeMap$ValueIterator.next
> 1706.03% 1700 java.util.TreeMap$PrivateEntryIterator.hasNext
> 6010002.13% 601
> scala.collection.convert.Wrappers$JIteratorWrapper.next
> 5160001.83% 516 writev
> --- 3885000 ns (13.79%), 3885 samples
> [ 0] java.util.TreeMap$PrivateEntryIterator.nextEntry
> [ 1] java.util.TreeMap$ValueIterator.next
> [ 2] scala.collection.convert.Wrappers$JIteratorWrapper.next
> [ 3] scala.collection.Iterator.find
> [ 4] scala.collection.Iterator.find$
> [ 5] scala.collection.AbstractIterator.find
> [ 6] scala.collection.IterableLike.find
> [ 7] scala.collection.IterableLike.find$
> [ 8] scala.collection.AbstractIterable.find
> [ 9] kafka.log.ProducerStateManager.lastStableOffset
> [10] kafka.log.Log.$anonfun$append$12
> [11] kafka.log.Log.$anonfun$append$2
> [12] kafka.log.Log.append
> [13] kafka.log.Log.appendAsFollower
> [14]
> kafka.cluster.Partition.$anonfun$doAppendRecordsToFollowerOrFutureReplica$1
> [15] kafka.cluster.Partition.doAppendRecordsToFollowerOrFutureReplica
> [16] kafka.cluster.Partition.appendRecordsToFollowerOrFutureReplica
> [17] kafka.server.ReplicaFetcherThread.processPartitionData
> [18] kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$7
> [19] kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$6
> [20]
> kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$6$adapted
> [21] kafka.server.AbstractFetcherThread$$Lambda$552.191789933.apply
> [22] scala.collection.mutable.ResizableArray.foreach
> [23] scala.collection.mutable.ResizableArray.foreach$
> [24] scala.collection.mutable.ArrayBuffer.foreach
> [25] kafka.server.AbstractFetcherThread.$anonfun$processFetchRequest$5
> [26] kafka.server.AbstractFetcherThread.processFetchRequest
> [27] kafka.server.AbstractFetcherThread.$anonfun$maybeFetch$3
> [28] kafka.server.AbstractFetcherThread.maybeFetch
> [29] kafka.server.AbstractFetcherThread.doWork
> [30] kafka.utils.ShutdownableThread.run
>
> {code}
> {code:java}
> --- 3632000 ns (12.89%), 3632 samples
> [ 0] scala.collection.convert.Wrappers$JIteratorWrapper.hasNext
> [ 1] scala.collection.Iterator.find
> [ 2] scala.collection.Iterator.find$
> [ 3] scala.collection.AbstractIterator.find
> [ 4] scala.collection.IterableLike.find
> [ 5] scala.collection.IterableLike.find$
> [ 6] scala.collection.AbstractIterable.find
> [ 7] kafka.log.ProducerStateManager.lastStableOffset
> [ 8] kafka.log.Log.$anonfun$append$12
> [ 9] kafka.log.Log.$anonfun$append$2
> [10] kafka.log.Log.append
> [11] kafka.log.Log.appendAsFollower
> [12]
> kafka.cluster.
