Thanks! Would it be possible for you to set depth=20 for that trace so we can see what selector is giving us the trouble? There are several for kafka as well as one for each zk connection...
-Jay On Thu, Aug 30, 2012 at 8:59 AM, Sam Meder <sam.me...@jivesoftware.com>wrote: > Sorry about taking a while (was on vacation). Before I get to the results > 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. > > Now, here is the hprof output: > > THREAD START (obj=500003ad, id = 200004, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=500003ad, id = 200005, name="RMI TCP Accept-9999", > group="system") > THREAD START (obj=500003ad, id = 200006, name="RMI TCP Accept-0", > group="system") > THREAD START (obj=500003ad, id = 200001, name="main", group="main") > THREAD START (obj=500003ad, id = 200007, name="Thread-2", group="main") > THREAD START (obj=500003ad, id = 200008, name="Thread-3", group="main") > THREAD START (obj=500003ad, id = 200009, name="kafka-processor-9092-0", > group="main") > THREAD START (obj=500003ad, id = 200010, name="kafka-processor-9092-1", > group="main") > THREAD START (obj=500003ad, id = 200011, name="kafka-acceptor", > group="main") > THREAD START (obj=5000074b, id = 200012, > name="ZkClient-EventThread-20-localhost:2181", group="main") > THREAD START (obj=5000076d, id = 200013, name="main-SendThread()", > group="main") > THREAD START (obj=5000076e, id = 200014, name="main-EventThread", > group="main") > THREAD START (obj=500003ad, id = 200015, > name="metrics-meter-tick-thread-1", group="main") > THREAD START (obj=500003ad, id = 200016, > name="metrics-meter-tick-thread-2", group="main") > THREAD START (obj=500003ad, id = 200017, name="request-expiration-task", > group="main") > THREAD START (obj=500003ad, id = 200018, name="request-expiration-task", > group="main") > THREAD START (obj=500003ad, id = 200019, name="kafka-request-handler-0", > group="main") > THREAD START (obj=500003ad, id = 200020, name="kafka-request-handler-1", > group="main") > THREAD START (obj=500003ad, id = 200021, name="Thread-6", group="main") > THREAD START (obj=500003ad, id = 200022, name="Thread-7", group="main") > THREAD START (obj=50000899, id = 200023, name="ReplicaFetcherThread-0-2 on > broker 1, ", group="main") > THREAD START (obj=50000899, id = 200024, name="ReplicaFetcherThread-0-3 on > broker 1, ", group="main") > THREAD START (obj=50000899, id = 200025, name="ReplicaFetcherThread-0-0 on > broker 1, ", group="main") > THREAD START (obj=50000899, id = 200026, name="ReplicaFetcherThread-0-1 on > broker 1, ", group="main") > THREAD START (obj=500003ad, id = 200028, name="SIGINT handler", > group="system") > THREAD START (obj=5000074b, id = 200029, name="Thread-0", group="main") > THREAD START (obj=5000074b, id = 200030, name="Thread-1", group="main") > THREAD START (obj=500003ad, id = 200031, name="Thread-5", group="main") > THREAD END (id = 200029) > THREAD END (id = 200031) > THREAD END (id = 200020) > THREAD END (id = 200019) > THREAD END (id = 200008) > THREAD END (id = 200022) > THREAD END (id = 200007) > THREAD END (id = 200021) > THREAD END (id = 200018) > THREAD END (id = 200017) > THREAD END (id = 200012) > THREAD END (id = 200014) > THREAD END (id = 200013) > THREAD END (id = 200025) > THREAD END (id = 200023) > THREAD END (id = 200026) > THREAD END (id = 200024) > THREAD END (id = 200011) > THREAD END (id = 200009) > THREAD END (id = 200010) > THREAD END (id = 200030) > THREAD END (id = 200028) > THREAD END (id = 200002) > TRACE 300680: > > 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) > TRACE 300425: > java.net.PlainSocketImpl.socketAccept(PlainSocketImpl.java:Unknown > line) > > java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) > java.net.ServerSocket.implAccept(ServerSocket.java:522) > java.net.ServerSocket.accept(ServerSocket.java:490) > TRACE 300886: > sun.misc.Unsafe.park(Unsafe.java:Unknown line) > > java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) > java.util.concurrent.DelayQueue.take(DelayQueue.java:220) > CPU SAMPLES BEGIN (total = 882945) Wed Aug 29 23:37:30 2012 > rank self accum count trace method > 1 72.49% 72.49% 640059 300680 sun.nio.ch.EPollArrayWrapper.epollWait > 2 27.25% 99.74% 240621 300425 java.net.PlainSocketImpl.socketAccept > 3 0.09% 99.83% 762 300886 sun.misc.Unsafe.park > CPU SAMPLES END > > Let me know if you need anything else. Certainly happy to share my config > files and the test program if you need them. > > /Sam > > On Aug 20, 2012, at 2:30 PM, Sam Meder wrote: > > > 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? > > > > /Sam > >
