[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15292319#comment-15292319 ] Manoj Ramakrishnan commented on KAFKA-493: -- Thanks! > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: 0.9.0.1-upgrade.png, Kafka-2014-11-10.snapshot.zip, > Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, > Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, > stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) > >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15292129#comment-15292129 ] Cosmin Marginean commented on KAFKA-493: [~manoj.ramakrish...@plantronics.com] We are using the Oracle JVM 1.8 (1.8.0_65 to be specific) in production. However, after the 0.9.0.1 upgrade this didn't reproduce at all (just checked the infra monitoring this evening and is fairly flat ever since). Hope this helps. > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: 0.9.0.1-upgrade.png, Kafka-2014-11-10.snapshot.zip, > Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, > Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, > stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15291584#comment-15291584 ] Manoj Ramakrishnan commented on KAFKA-493: -- [~cosmin.marginean] We are running into something similar. Whenever we have consumer connected, we see the CPU bumps to about 100% and stays there. When consumers are stopped, the CPU goes down. We see similar the following stack as some others have noted. To make sure that is not a jdk issue, what version of java jdk are you running on ? > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: 0.9.0.1-upgrade.png, Kafka-2014-11-10.snapshot.zip, > Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, > Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, > stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15257799#comment-15257799 ] jaikiran pai commented on KAFKA-493: FWIW - we have been seeing a similar issue in 0.8 and also in 0.9.0.1 (latest release). We have been able to narrow it down a bit which I've have explained and asked for inputs in this mail on the user list http://mail-archives.apache.org/mod_mbox/kafka-users/201604.mbox/%3C571F23ED.7050405%40gmail.com%3E > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: 0.9.0.1-upgrade.png, Kafka-2014-11-10.snapshot.zip, > Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, > Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, > stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15210094#comment-15210094 ] Ismael Juma commented on KAFKA-493: --- Thanks for reporting back Cosmin. > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: 0.9.0.1-upgrade.png, Kafka-2014-11-10.snapshot.zip, > Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, > Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, > stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15210092#comment-15210092 ] Cosmin Marginean commented on KAFKA-493: I can confirm that we're been running 0.9.0.1 for over a week now and none of the CPU issues are present anymore (See 0.9.0.1-upgrade.png. I will make sure to update this if it regresses. > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, > Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, > Kafka-trace3.zip, backtraces.txt, stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15210084#comment-15210084 ] Li Jinyu commented on KAFKA-493: I have the same problem with 0.8.2.2 cluster, the CPU usage is really high, PID USER PR NI VIRT RES SHR S %CPU %MEMTIME+ COMMAND 40442 root 20 0 11.3g 606m 16m S 1040.0 3.8 36:42.34 java this cluster was upgraded from 0.8.1.1, as some issues found. leaders changed frequently, and sometimes one node was alive but zookeeper cannot see it. but in another 0.8.2.2 cluster, everything is fine. I tried to delete all data on one node as I thought it's caused by corrupted message data, but it didn't work. > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, > Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, > Kafka-trace3.zip, backtraces.txt, stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15193245#comment-15193245 ] Cosmin Marginean commented on KAFKA-493: Thanks Andrew. Will do this in the next few weeks. > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, > Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, > Kafka-trace3.zip, backtraces.txt, stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) > sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) > sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) > sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15163413#comment-15163413 ] Andrew Olson commented on KAFKA-493: [~cosmin.marginean] You might try upgrading to 0.9.0.1 which was just released last week. It has a couple of bug fixes (KAFKA-3159 and KAFKA-3003) that may be applicable. > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Fix For: 0.10.1.0 > > Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, > Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, > Kafka-trace3.zip, backtraces.txt, stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > TRACE 301281: > sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown > line) > sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) >
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15163367#comment-15163367 ] Cosmin Marginean commented on KAFKA-493: Does anyone have any updates on this or would you require any additional information to diagnose this? I can confirm that a cluster of 2 Kafka nodes running for the past few weeks has been constantly at over 70% CPU utilisation. with a very small amount of messages (a few thousand a day). What's worse, the CPU still stays very high when there's no activity on any of the topics. Is there any other JIRA ticket that has followed up on this separately? FYI, using 0.9.0.0 > High CPU usage on inactive server > - > > Key: KAFKA-493 > URL: https://issues.apache.org/jira/browse/KAFKA-493 > Project: Kafka > Issue Type: Bug > Components: core >Affects Versions: 0.8.0 >Reporter: Jay Kreps > Fix For: 0.10.1.0 > > Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, > Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, > Kafka-trace3.zip, backtraces.txt, stacktrace.txt > > > > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU > > usage is fairly high (13% of a > > core). Is that to be expected? I did look at the stack, but didn't see > > anything obvious. A background > > task? > > I wanted to mention how I am getting into this state. I've set up two > > machines with the latest 0.8 > > code base and am using a replication factor of 2. On starting the brokers > > there is no idle CPU activity. > > Then I run a test that essential does 10k publish operations followed by > > immediate consume operations > > (I was measuring latency). Once this has run the kafka nodes seem to > > consistently be consuming CPU > > essentially forever. > hprof results: > THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-", > group="system") > THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=53ae, id = 21, name="main", group="main") > THREAD START (obj=53ae, id = 27, name="Thread-2", group="main") > THREAD START (obj=53ae, id = 28, name="Thread-3", group="main") > THREAD START (obj=53ae, id = 29, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=53ae, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=53ae, id = 200011, name="kafka-acceptor", group="main") > THREAD START (obj=574b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=576e, id = 200014, name="main-SendThread()", > group="main") > THREAD START (obj=576d, id = 200013, name="main-EventThread", > group="main") > THREAD START (obj=53ae, id = 200015, name="metrics-meter-tick-thread-1", > group="main") > THREAD START (obj=53ae, id = 200016, name="metrics-meter-tick-thread-2", > group="main") > THREAD START (obj=53ae, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=53ae, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=53ae, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=53ae, id = 200021, name="Thread-6", group="main") > THREAD START (obj=53ae, id = 200022, name="Thread-7", group="main") > THREAD START (obj=5899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=5899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=53ae, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=53ae, id = 200029, name="Thread-5", group="main") > THREAD START (obj=574b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=574b, id = 200031, name="Thread-0", group="main") > THREAD END (id = 200031) > THREAD END (id = 200029) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 28) > THREAD END (id = 200021) > THREAD END (id = 27) > THREAD END (id = 200022) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200013) > THREAD END (id = 200014) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 29) > THREAD
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[
https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15022364#comment-15022364
]
Cosmin Marginean commented on KAFKA-493:
Hi guys
This seems to have been inactive for a while but I can confirm that I met
similar conditions (high number of partitions - 256 per topic) and get a high
CPU usage, but only while having producers/consumers wired. As soon as I
shutdown the client apps, CPU usage goes considerably low. Just wanted to know
if this is related or if this is something I should investigate and provide
diagnosis for in a separate ticket.
Below I managed to identify the threads that generate this high CPU usage.
{code}
"kafka-network-thread-9092-2" #24 prio=5 os_prio=0 tid=0x7f3f085a
nid=0xe96 runnable [0x7f3ee8ef3000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0xd4d6e6c8> (a sun.nio.ch.Util$2)
- locked <0xd4d6e6b0> (a java.util.Collections$UnmodifiableSet)
- locked <0xd4d77ac8> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at kafka.network.Processor.run(SocketServer.scala:320)
at java.lang.Thread.run(Thread.java:745)
"kafka-network-thread-9092-1" #23 prio=5 os_prio=0 tid=0x7f3f08585000
nid=0xe95 runnable [0x7f3ee8ff4000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0xd4d6e6f8> (a sun.nio.ch.Util$2)
- locked <0xd4d6e6e0> (a java.util.Collections$UnmodifiableSet)
- locked <0xd4d77b58> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at kafka.network.Processor.run(SocketServer.scala:320)
at java.lang.Thread.run(Thread.java:745)
"kafka-network-thread-9092-0" #22 prio=5 os_prio=0 tid=0x7f3f0856a800
nid=0xe94 runnable [0x7f3ee90f5000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
- locked <0xd4d7c4e8> (a sun.nio.ch.Util$2)
- locked <0xd4d7c4d0> (a java.util.Collections$UnmodifiableSet)
- locked <0xd4d77be8> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at kafka.network.Processor.run(SocketServer.scala:320)
at java.lang.Thread.run(Thread.java:745)
{code}
> High CPU usage on inactive server
> -
>
> Key: KAFKA-493
> URL: https://issues.apache.org/jira/browse/KAFKA-493
> Project: Kafka
> Issue Type: Bug
> Components: core
>Affects Versions: 0.8.0
>Reporter: Jay Kreps
> Fix For: 0.10.0.0
>
> Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip,
> Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip,
> Kafka-trace3.zip, backtraces.txt, stacktrace.txt
>
>
> > I've been playing with the 0.8 branch of Kafka and noticed that idle CPU
> > usage is fairly high (13% of a
> > core). Is that to be expected? I did look at the stack, but didn't see
> > anything obvious. A background
> > task?
> > I wanted to mention how I am getting into this state. I've set up two
> > machines with the latest 0.8
> > code base and am using a replication factor of 2. On starting the brokers
> > there is no idle CPU activity.
> > Then I run a test that essential does 10k publish operations followed by
> > immediate consume operations
> > (I was measuring latency). Once this has run the kafka nodes seem to
> > consistently be consuming CPU
> > essentially forever.
> hprof results:
> THREAD START (obj=53ae, id = 24, name="RMI TCP Accept-0",
> group="system")
> THREAD START (obj=53ae, id = 25, name="RMI TCP Accept-",
> group="system")
> THREAD START (obj=53ae, id = 26, name="RMI TCP Accept-0",
> group="system")
> THREAD START (obj=53ae, id = 21, name="main", group="main")
> THREAD START (obj=53ae, id = 27, name="Thread-2", group="main")
> THREAD START (obj=53ae, id = 28,
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14311032#comment-14311032 ] Olson,Andrew commented on KAFKA-493: I will be out of the office until Monday, 3/2/2015. Andrew Olson | Sr. Software Architect | Cerner Corporation | 816.201.3825 | aols...@cerner.com | www.cerner.com CONFIDENTIALITY NOTICE This message and any included attachments are from Cerner Corporation and are intended only for the addressee. The information contained in this message is confidential and may constitute inside or non-public information under international, federal, or state securities laws. Unauthorized forwarding, printing, copying, distribution, or use of such information is strictly prohibited and may be unlawful. If you are not the addressee, please promptly delete this message and notify the sender of the delivery error by e-mail or you may call Cerner's corporate offices in Kansas City, Missouri, U.S.A at (+1) (816)221-1024. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.9.0 Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14213272#comment-14213272 ] Jun Rao commented on KAFKA-493: --- [~activars], how do I look at the snapshot? Could you include the top few methods? High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.9.0 Attachments: Kafka-2014-11-10.snapshot.zip, Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14201913#comment-14201913 ] Jing Dong commented on KAFKA-493: - [~smeder] Do you have the hprof command you used? I can provide a similar CPU profiling result to see if we are having the same issue or it could be happening in multiple places. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.9.0 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14202228#comment-14202228 ] Sam Meder commented on KAFKA-493: - Sorry, don't have that anymore - it's been too long High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.9.0 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14202310#comment-14202310 ] Jing Dong commented on KAFKA-493: - [~smeder] Thanks for the response - do you remember what's the class entry used the hprof? High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.9.0 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=14122100#comment-14122100 ] Guozhang Wang commented on KAFKA-493: - Moving the fix of 2) to 0.9 High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103) java.nio.channels.Channels$ReadableByteChannelImpl.read(Channels.java:385)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13974471#comment-13974471 ] Joel Koshy commented on KAFKA-493: -- For (1) I think the issue was discussed (not yet fixed) in KAFKA-1150 High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13972963#comment-13972963 ] Andrew Olson commented on KAFKA-493: Repeated the previous test using YourKit for profiling, trace snapshot files are attached. Will post a summary of my findings later this morning. The epollWait does not appear to be a problem. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13973114#comment-13973114 ] Andrew Olson commented on KAFKA-493: Looks like a large amount of time is spent in the ensureTopicExists method as it iterates over the metadata cache map until it finds a matching topic (this is especially problematic (O(n²)) when processing messages that reference a large number of partitions, like the replicas fetch requests that are continually sent). Fortunately this appears to have already been fixed in trunk/0.8.1.1 by KAFKA-1356 by changing the metadata cache from a Map [TopicAndPartition,PartitionStateInfo] to a Map[Topic, Map[Partition, PartitionStateInfo]]. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13973205#comment-13973205 ] Joel Koshy commented on KAFKA-493: -- Actually, looking at the code it must be due to follower fetch requests. Can you confirm that in your broker request logs? High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13973313#comment-13973313 ] Andrew Olson commented on KAFKA-493: I built and deployed the latest trunk code to test the benefit of KAFKA-1356. CPU usage was reduced some, but unfortunately still relatively high, around 35-40% of a core. The sun.nio.ch.SocketChannelImpl.write(ByteBuffer) and sun.nio.ch.SocketChannelImpl.read(ByteBuffer) methods were the top two hot spots, and profiling didn't reveal any obvious opportunities for optimization. Looking at the ReplicaFetcherThread metrics, the fetch response message size is 20-25kb. Changing replica.fetch.wait.max.ms from the default value of 500 to 1 (along with setting replica.lag.time.max.ms=3) cut CPU to about 5-10% of a core, which seems reasonable. Predictably, there were clear spikes on the CPU graph up to 30-50% every 10 seconds that appear to account for the vast majority of overall CPU use. What are the disadvantages of significantly decreasing the replica fetch frequency like this? Would it affect synchronous producer performance? With a large number of partitions being replicated, it seems like a configuration change that might be beneficial. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13973365#comment-13973365 ] Jay Kreps commented on KAFKA-493: - Ideally there should be no downside of longer expiration times. However there are two bugs that lead to us setting that lower timeout: 1. I think there is a race condition that effects messages with acks=-1 (full commit) which can lead to waiting until the full fetch timeout to acknowledge the producer in rare cases. Not sure if this issue still exists. 2. The second issue was that when the fetcher disconnects we don't proactively purge any asynchronous requests it has. So very long timeouts combined with a consumer with high error rate can accumulate memory. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: Kafka-sampling1.zip, Kafka-sampling2.zip, Kafka-sampling3.zip, Kafka-trace1.zip, Kafka-trace2.zip, Kafka-trace3.zip, backtraces.txt, stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13970024#comment-13970024 ] Andrew Olson commented on KAFKA-493: Due to some concerns about partition count scalability, I setup a test that created a large number of idle topics (4 partitions per topic, replication factor = 3), periodically pausing topic creation to inspect the overall health of the Kafka cluster. I noticed that the CPU usage increased proportionally to the total number of topics/partitions. - With 50 topics and 200 partitions per broker, CPU consumption was averaging about 5% of a core on each system. - With 500 topics and 2000 partitions per broker, CPU consumption was averaging about 50% of a core, occasionally spiking up to 70%. - With 1000 topics and 4000 partitions per broker, CPU consumption started to approach 100% of a core. VisualVM showed that most of the time was being spent in epollWait. The Kafka cluster for this test is using Java version 1.7.0_25 on Redhat 6.2. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id =
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13970049#comment-13970049 ] Jay Kreps commented on KAFKA-493: - Hmm, this definitely sounds like a bug. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103) java.nio.channels.Channels$ReadableByteChannelImpl.read(Channels.java:385) kafka.utils.Utils$.read(Utils.scala:453)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13970427#comment-13970427 ] Sam Meder commented on KAFKA-493: - Do you know if VisualVM uses sampling to arrive at that conclusion? Since epollWait just blocks in a system call sampling won't be accurate in this case... High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103) java.nio.channels.Channels$ReadableByteChannelImpl.read(Channels.java:385)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13970458#comment-13970458 ] Joel Koshy commented on KAFKA-493: -- I would echo Sam's comment. Personally, I prefer using plain hprof or yourkit for cpu profiling - its profiling overhead is pretty low and seems to give more accurate results. It (by default) takes into account zero-time methods such as sleep, accept, epollWait, etc. I think visualvm also supports that but at the class level and is not enabled by default (afaik). High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[jira] [Commented] (KAFKA-493) High CPU usage on inactive server
[ https://issues.apache.org/jira/browse/KAFKA-493?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanelfocusedCommentId=13888711#comment-13888711 ] Neha Narkhede commented on KAFKA-493: - We should try this on Java 7 and observe the CPU usage. High CPU usage on inactive server - Key: KAFKA-493 URL: https://issues.apache.org/jira/browse/KAFKA-493 Project: Kafka Issue Type: Bug Components: core Affects Versions: 0.8.0 Reporter: Jay Kreps Fix For: 0.8.2 Attachments: stacktrace.txt I've been playing with the 0.8 branch of Kafka and noticed that idle CPU usage is fairly high (13% of a core). Is that to be expected? I did look at the stack, but didn't see anything obvious. A background task? I wanted to mention how I am getting into this state. I've set up two machines with the latest 0.8 code base and am using a replication factor of 2. On starting the brokers there is no idle CPU activity. Then I run a test that essential does 10k publish operations followed by immediate consume operations (I was measuring latency). Once this has run the kafka nodes seem to consistently be consuming CPU essentially forever. hprof results: THREAD START (obj=53ae, id = 24, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 25, name=RMI TCP Accept-, group=system) THREAD START (obj=53ae, id = 26, name=RMI TCP Accept-0, group=system) THREAD START (obj=53ae, id = 21, name=main, group=main) THREAD START (obj=53ae, id = 27, name=Thread-2, group=main) THREAD START (obj=53ae, id = 28, name=Thread-3, group=main) THREAD START (obj=53ae, id = 29, name=kafka-processor-9092-0, group=main) THREAD START (obj=53ae, id = 200010, name=kafka-processor-9092-1, group=main) THREAD START (obj=53ae, id = 200011, name=kafka-acceptor, group=main) THREAD START (obj=574b, id = 200012, name=ZkClient-EventThread-20-localhost:2181, group=main) THREAD START (obj=576e, id = 200014, name=main-SendThread(), group=main) THREAD START (obj=576d, id = 200013, name=main-EventThread, group=main) THREAD START (obj=53ae, id = 200015, name=metrics-meter-tick-thread-1, group=main) THREAD START (obj=53ae, id = 200016, name=metrics-meter-tick-thread-2, group=main) THREAD START (obj=53ae, id = 200017, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200018, name=request-expiration-task, group=main) THREAD START (obj=53ae, id = 200019, name=kafka-request-handler-0, group=main) THREAD START (obj=53ae, id = 200020, name=kafka-request-handler-1, group=main) THREAD START (obj=53ae, id = 200021, name=Thread-6, group=main) THREAD START (obj=53ae, id = 200022, name=Thread-7, group=main) THREAD START (obj=5899, id = 200023, name=ReplicaFetcherThread-0-2 on broker 1, , group=main) THREAD START (obj=5899, id = 200024, name=ReplicaFetcherThread-0-3 on broker 1, , group=main) THREAD START (obj=5899, id = 200025, name=ReplicaFetcherThread-0-0 on broker 1, , group=main) THREAD START (obj=5899, id = 200026, name=ReplicaFetcherThread-0-1 on broker 1, , group=main) THREAD START (obj=53ae, id = 200028, name=SIGINT handler, group=system) THREAD START (obj=53ae, id = 200029, name=Thread-5, group=main) THREAD START (obj=574b, id = 200030, name=Thread-1, group=main) THREAD START (obj=574b, id = 200031, name=Thread-0, group=main) THREAD END (id = 200031) THREAD END (id = 200029) THREAD END (id = 200020) THREAD END (id = 200019) THREAD END (id = 28) THREAD END (id = 200021) THREAD END (id = 27) THREAD END (id = 200022) THREAD END (id = 200018) THREAD END (id = 200017) THREAD END (id = 200012) THREAD END (id = 200013) THREAD END (id = 200014) THREAD END (id = 200025) THREAD END (id = 200023) THREAD END (id = 200026) THREAD END (id = 200024) THREAD END (id = 200011) THREAD END (id = 29) THREAD END (id = 200010) THREAD END (id = 200030) THREAD END (id = 200028) TRACE 301281: sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java:Unknown line) sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228) sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81) sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) sun.nio.ch.SocketAdaptor$SocketInputStream.read(SocketAdaptor.java:218) sun.nio.ch.ChannelInputStream.read(ChannelInputStream.java:103) java.nio.channels.Channels$ReadableByteChannelImpl.read(Channels.java:385) kafka.utils.Utils$.read(Utils.scala:453)
