You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@zookeeper.apache.org by Satish Bhatti <ct...@gmail.com> on 2009/06/02 21:07:48 UTC

ZooKeeper heavy CPU utilisation

I am running a 5 node ZooKeeper cluster and I noticed that one of them has
very high CPU usage:

 PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND
 6883  infact       22   0   725m  41m  4188 S   95       0.5
 5671:54  java

It is not "doing anything" application-wise at this point, so I was
wondering why the heck it's using up so much CPU!  I have attached a jstack
logfile to this email.

Satish

Re: ZooKeeper heavy CPU utilisation

Posted by Patrick Hunt <ph...@apache.org>.
Turns out there is a bug in the JDK:

https://issues.apache.org/jira/browse/ZOOKEEPER-427?focusedCommentId=12716020&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#action_12716020

We are looking to see if we can solve this via some workaround in 3.2. 
Currently the only solution is to restart the server that experiences 
this problem.

Patrick

Patrick Hunt wrote:
> According to your trace I see you are using jvm 1.6.0_03-b05
> 
> One of the bugs fixed in:
> http://java.sun.com/javase/6/webnotes/6u4.html
> specifically:
> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6403933
> seems to have a description very close to what you are seeing.
> 
> Perhaps you can try running with the latest (or as recent as you can 
> get) jvm?
> 
> Patrick
> 
> Satish Bhatti wrote:
>> stat
>> Zookeeper version: 3.1.1-755636, built on 03/18/2009 16:52 GMT
>> Clients:
>>  /127.0.0.1:42460[1](queued=0,recved=0,sent=0)
>>  /172.16.0.178:34283[1](queued=0,recved=925109,sent=925109)
>>
>> Latency min/avg/max: 0/0/220
>> Received: 925109
>> Sent: 925109
>> Outstanding: 0
>> Zxid: 0x50051c7b3
>> Mode: follower
>> Node count: 11
>> Connection closed by foreign host.
>>
>>
>> On Tue, Jun 2, 2009 at 1:39 PM, Ted Dunning <te...@gmail.com> 
>> wrote:
>>
>>> I am sooo glad I put in the fourth item.  This is clearly not 
>>> overload in
>>> that sense.
>>>
>>> Do you have logs from the ZK?
>>>
>>> What does the stat command return (telnet to the ZK inquestion, type 
>>> "stat"
>>> (without the quotes)).
>>>
>>> On Tue, Jun 2, 2009 at 1:35 PM, Satish Bhatti <ct...@gmail.com> 
>>> wrote:
>>>
>>>> I have a grand total of 3 files, each holding a single long!  Could it
>>>> really be in gc hell because of this?  I passed in -Xmx256m on the
>>> command
>>>> line.
>>>>
>>>
>>>
>>> -- 
>>> Ted Dunning, CTO
>>> DeepDyve
>>>
>>

Re: ZooKeeper heavy CPU utilisation

Posted by Patrick Hunt <ph...@apache.org>.
According to your trace I see you are using jvm 1.6.0_03-b05

One of the bugs fixed in:
http://java.sun.com/javase/6/webnotes/6u4.html
specifically:
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6403933
seems to have a description very close to what you are seeing.

Perhaps you can try running with the latest (or as recent as you can 
get) jvm?

Patrick

Satish Bhatti wrote:
> stat
> Zookeeper version: 3.1.1-755636, built on 03/18/2009 16:52 GMT
> Clients:
>  /127.0.0.1:42460[1](queued=0,recved=0,sent=0)
>  /172.16.0.178:34283[1](queued=0,recved=925109,sent=925109)
> 
> Latency min/avg/max: 0/0/220
> Received: 925109
> Sent: 925109
> Outstanding: 0
> Zxid: 0x50051c7b3
> Mode: follower
> Node count: 11
> Connection closed by foreign host.
> 
> 
> On Tue, Jun 2, 2009 at 1:39 PM, Ted Dunning <te...@gmail.com> wrote:
> 
>> I am sooo glad I put in the fourth item.  This is clearly not overload in
>> that sense.
>>
>> Do you have logs from the ZK?
>>
>> What does the stat command return (telnet to the ZK inquestion, type "stat"
>> (without the quotes)).
>>
>> On Tue, Jun 2, 2009 at 1:35 PM, Satish Bhatti <ct...@gmail.com> wrote:
>>
>>> I have a grand total of 3 files, each holding a single long!  Could it
>>> really be in gc hell because of this?  I passed in -Xmx256m on the
>> command
>>> line.
>>>
>>
>>
>> --
>> Ted Dunning, CTO
>> DeepDyve
>>
> 

Re: ZooKeeper heavy CPU utilisation

Posted by Satish Bhatti <ct...@gmail.com>.
[infact@df3-8 infact]$ echo stats | nc localhost 2181
Zookeeper version: 3.1.1-755636, built on 03/18/2009 16:52 GMT
Clients:
 /127.0.0.1:33139[1](queued=0,recved=0,sent=0)
 /172.16.0.178:34283[1](queued=0,recved=925371,sent=925371)

Latency min/avg/max: 0/0/220
Received: 925371
Sent: 925382
Outstanding: 0
Zxid: 0x50051cda1
Mode: follower
Node count: 11

As you can see, the sent/received numbers haven't gone up excessively since
the last stats command.

On Tue, Jun 2, 2009 at 2:03 PM, Ted Dunning <te...@gmail.com> wrote:

> Are the sent and received numbers going up quickly?
>
> What is the second client doing?
>
> On Tue, Jun 2, 2009 at 1:49 PM, Satish Bhatti <ct...@gmail.com> wrote:
>
> > stat
> > Zookeeper version: 3.1.1-755636, built on 03/18/2009 16:52 GMT
> > Clients:
> >  /127.0.0.1:42460[1](queued=0,recved=0,sent=0)
> >  /172.16.0.178:34283[1](queued=0,recved=925109,sent=925109)
> >
> > Latency min/avg/max: 0/0/220
> > Received: 925109
> > Sent: 925109
> > Outstanding: 0
> > Zxid: 0x50051c7b3
> > Mode: follower
> > Node count: 11
> > Connection closed by foreign host.
> >
> >
> > On Tue, Jun 2, 2009 at 1:39 PM, Ted Dunning <te...@gmail.com>
> wrote:
> >
> > > I am sooo glad I put in the fourth item.  This is clearly not overload
> in
> > > that sense.
> > >
> > > Do you have logs from the ZK?
> > >
> > > What does the stat command return (telnet to the ZK inquestion, type
> > "stat"
> > > (without the quotes)).
> > >
> > > On Tue, Jun 2, 2009 at 1:35 PM, Satish Bhatti <ct...@gmail.com>
> > wrote:
> > >
> > > > I have a grand total of 3 files, each holding a single long!  Could
> it
> > > > really be in gc hell because of this?  I passed in -Xmx256m on the
> > > command
> > > > line.
> > > >
> > >
> > >
> > >
> > > --
> > > Ted Dunning, CTO
> > > DeepDyve
> > >
> >
>
>
>
> --
> Ted Dunning, CTO
> DeepDyve
>
> 111 West Evelyn Ave. Ste. 202
> Sunnyvale, CA 94086
> http://www.deepdyve.com
> 858-414-0013 (m)
> 408-773-0220 (fax)
>

Re: ZooKeeper heavy CPU utilisation

Posted by Ted Dunning <te...@gmail.com>.
Are the sent and received numbers going up quickly?

What is the second client doing?

On Tue, Jun 2, 2009 at 1:49 PM, Satish Bhatti <ct...@gmail.com> wrote:

> stat
> Zookeeper version: 3.1.1-755636, built on 03/18/2009 16:52 GMT
> Clients:
>  /127.0.0.1:42460[1](queued=0,recved=0,sent=0)
>  /172.16.0.178:34283[1](queued=0,recved=925109,sent=925109)
>
> Latency min/avg/max: 0/0/220
> Received: 925109
> Sent: 925109
> Outstanding: 0
> Zxid: 0x50051c7b3
> Mode: follower
> Node count: 11
> Connection closed by foreign host.
>
>
> On Tue, Jun 2, 2009 at 1:39 PM, Ted Dunning <te...@gmail.com> wrote:
>
> > I am sooo glad I put in the fourth item.  This is clearly not overload in
> > that sense.
> >
> > Do you have logs from the ZK?
> >
> > What does the stat command return (telnet to the ZK inquestion, type
> "stat"
> > (without the quotes)).
> >
> > On Tue, Jun 2, 2009 at 1:35 PM, Satish Bhatti <ct...@gmail.com>
> wrote:
> >
> > > I have a grand total of 3 files, each holding a single long!  Could it
> > > really be in gc hell because of this?  I passed in -Xmx256m on the
> > command
> > > line.
> > >
> >
> >
> >
> > --
> > Ted Dunning, CTO
> > DeepDyve
> >
>



-- 
Ted Dunning, CTO
DeepDyve

111 West Evelyn Ave. Ste. 202
Sunnyvale, CA 94086
http://www.deepdyve.com
858-414-0013 (m)
408-773-0220 (fax)

Re: ZooKeeper heavy CPU utilisation

Posted by Satish Bhatti <ct...@gmail.com>.
stat
Zookeeper version: 3.1.1-755636, built on 03/18/2009 16:52 GMT
Clients:
 /127.0.0.1:42460[1](queued=0,recved=0,sent=0)
 /172.16.0.178:34283[1](queued=0,recved=925109,sent=925109)

Latency min/avg/max: 0/0/220
Received: 925109
Sent: 925109
Outstanding: 0
Zxid: 0x50051c7b3
Mode: follower
Node count: 11
Connection closed by foreign host.


On Tue, Jun 2, 2009 at 1:39 PM, Ted Dunning <te...@gmail.com> wrote:

> I am sooo glad I put in the fourth item.  This is clearly not overload in
> that sense.
>
> Do you have logs from the ZK?
>
> What does the stat command return (telnet to the ZK inquestion, type "stat"
> (without the quotes)).
>
> On Tue, Jun 2, 2009 at 1:35 PM, Satish Bhatti <ct...@gmail.com> wrote:
>
> > I have a grand total of 3 files, each holding a single long!  Could it
> > really be in gc hell because of this?  I passed in -Xmx256m on the
> command
> > line.
> >
>
>
>
> --
> Ted Dunning, CTO
> DeepDyve
>

Re: ZooKeeper heavy CPU utilisation

Posted by Ted Dunning <te...@gmail.com>.
I am sooo glad I put in the fourth item.  This is clearly not overload in
that sense.

Do you have logs from the ZK?

What does the stat command return (telnet to the ZK inquestion, type "stat"
(without the quotes)).

On Tue, Jun 2, 2009 at 1:35 PM, Satish Bhatti <ct...@gmail.com> wrote:

> I have a grand total of 3 files, each holding a single long!  Could it
> really be in gc hell because of this?  I passed in -Xmx256m on the command
> line.
>



-- 
Ted Dunning, CTO
DeepDyve

Re: ZooKeeper heavy CPU utilisation

Posted by Satish Bhatti <ct...@gmail.com>.
Hey Ted,
I have a grand total of 3 files, each holding a single long!  Could it
really be in gc hell because of this?  I passed in -Xmx256m on the command
line.

Satish

On Tue, Jun 2, 2009 at 12:52 PM, Ted Dunning <te...@gmail.com> wrote:

> I have seen this when I was over-loading our zookeeper instance.  When
> total
> data or total number of files gets large, the system can wind up in GC
> almost permanently.  Zookeeper being Zookeeper, it does an amazing job of
> keeping on, but eventually things go bad.
>
> To test if this is your problem, you can do a couple of things.
>
> - first, figure out how many files you have and how much space they take
>
> - second, review how much memory you gave ZK to start.  It looks from what
> you show here that you didn't give it much memory.
>
> - third, turn on verbose GC and see what that says.
>
> - fourth, write back and tell me why I was wrong with this guess so that we
> all get smarter!
>
> On Tue, Jun 2, 2009 at 12:07 PM, Satish Bhatti <ct...@gmail.com> wrote:
>
> > I am running a 5 node ZooKeeper cluster and I noticed that one of them
> has
> > very high CPU usage:
> >
> >  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND
> >  6883  infact       22   0   725m  41m  4188 S   95       0.5
> >  5671:54  java
> >
> > It is not "doing anything" application-wise at this point, so I was
> > wondering why the heck it's using up so much CPU!  I have attached a
> jstack
> > logfile to this email.
> >
> > Satish
> >
> >
>
>
> --
> Ted Dunning, CTO
> DeepDyve
>
> 111 West Evelyn Ave. Ste. 202
> Sunnyvale, CA 94086
> http://www.deepdyve.com
> 858-414-0013 (m)
> 408-773-0220 (fax)
>

Re: ZooKeeper heavy CPU utilisation

Posted by Ted Dunning <te...@gmail.com>.
I have seen this when I was over-loading our zookeeper instance.  When total
data or total number of files gets large, the system can wind up in GC
almost permanently.  Zookeeper being Zookeeper, it does an amazing job of
keeping on, but eventually things go bad.

To test if this is your problem, you can do a couple of things.

- first, figure out how many files you have and how much space they take

- second, review how much memory you gave ZK to start.  It looks from what
you show here that you didn't give it much memory.

- third, turn on verbose GC and see what that says.

- fourth, write back and tell me why I was wrong with this guess so that we
all get smarter!

On Tue, Jun 2, 2009 at 12:07 PM, Satish Bhatti <ct...@gmail.com> wrote:

> I am running a 5 node ZooKeeper cluster and I noticed that one of them has
> very high CPU usage:
>
>  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND
>  6883  infact       22   0   725m  41m  4188 S   95       0.5
>  5671:54  java
>
> It is not "doing anything" application-wise at this point, so I was
> wondering why the heck it's using up so much CPU!  I have attached a jstack
> logfile to this email.
>
> Satish
>
>


-- 
Ted Dunning, CTO
DeepDyve

111 West Evelyn Ave. Ste. 202
Sunnyvale, CA 94086
http://www.deepdyve.com
858-414-0013 (m)
408-773-0220 (fax)

Re: ZooKeeper heavy CPU utilisation

Posted by Satish Bhatti <ct...@gmail.com>.
Created a Jira and attached logile + jstack file to it.
https://issues.apache.org/jira/secure/ManageAttachments.jspa?id=12426974


On Tue, Jun 2, 2009 at 1:50 PM, Mahadev Konar <ma...@yahoo-inc.com> wrote:

> Hi Satish,
>  Can you attach this trace to a jira? Please open one for this. Also, can
> you do the following -
>
> For all the threads for the zookeeper server you are seeing the problem on,
>
> Can you do an strace on all the threads and see which thread is spinning?
>
> Also, can you upload the configs of the servers to the jira that you
> create?
>
> mahadev
>
>
> On 6/2/09 1:29 PM, "Satish Bhatti" <ct...@gmail.com> wrote:
>
> > Hey Ben,
> > Strange you didn't get the attachment, my gmail is showing the paper clip
> > thingy for that message.  ANyway, I have pasted the whole jstack output
> into
> > this email, since it's pretty small.
> >
> > Satish
> >
> > 2009-06-02 11:56:26
> > Full thread dump Java HotSpot(TM) 64-Bit Server VM (1.6.0_03-b05 mixed
> > mode):
> >
> > "Attach Listener" daemon prio=10 tid=0x0000000043e71800 nid=0x5566
> waiting
> > on condition [0x0000000000000000..0x0000000000000000]
> >    java.lang.Thread.State: RUNNABLE
> >
> > "SyncThread:4" prio=10 tid=0x00002aaac8274800 nid=0x1ced waiting on
> > condition [0x0000000042d63000..0x0000000042d63c10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34e44d8> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> >
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> > at
> >
> org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java
> > :71)
> >
> > "FollowerRequestProcessor:4" prio=10 tid=0x00002aaac8273c00 nid=0x1cec
> > waiting on condition [0x0000000042b61000..0x0000000042b61b90]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34e4648> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> >
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> > at
> >
> org.apache.zookeeper.server.quorum.FollowerRequestProcessor.run(FollowerReques
> > tProcessor.java:58)
> >
> > "CommitProcessor:4" prio=10 tid=0x00002aaac8150400 nid=0x1ceb in
> > Object.wait() [0x0000000042c62000..0x0000000042c62b10]
> >    java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0x00002aaab34e46f0> (a
> > org.apache.zookeeper.server.quorum.CommitProcessor)
> > at java.lang.Object.wait(Object.java:485)
> > at
> >
>
> org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:80>
> )
> > - locked <0x00002aaab34e46f0> (a
> > org.apache.zookeeper.server.quorum.CommitProcessor)
> >
> > "Thread-13" daemon prio=10 tid=0x00002aaac80f9800 nid=0x1b5e runnable
> > [0x0000000042a60000..0x0000000042a60c90]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.FileDispatcher.read0(Native Method)
> > at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> > at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> > at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> > at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> > - locked <0x00002aaab34bf5c8> (a java.lang.Object)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> > nager.java:551)
> >
> > "Thread-12" daemon prio=10 tid=0x00002aaac80f8c00 nid=0x1b5d waiting on
> > condition [0x0000000042258000..0x0000000042258c10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34bf7c0> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> > nager.java:479)
> >
> > "Thread-11" prio=10 tid=0x0000000043d22800 nid=0x1b5c runnable
> > [0x000000004295f000..0x000000004295fb90]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.FileDispatcher.read0(Native Method)
> > at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> > at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> > at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> > at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> > - locked <0x00002aaab34bf9a8> (a java.lang.Object)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> > nager.java:551)
> >
> > "Thread-10" prio=10 tid=0x0000000043d21400 nid=0x1b5b waiting on
> condition
> > [0x000000004285e000..0x000000004285eb10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34bfbf8> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> > nager.java:479)
> >
> > "Thread-9" prio=10 tid=0x0000000043d1d800 nid=0x1b5a runnable
> > [0x000000004275d000..0x000000004275da90]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.FileDispatcher.read0(Native Method)
> > at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> > at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> > at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> > at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> > - locked <0x00002aaab34c06c8> (a java.lang.Object)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> > nager.java:551)
> >
> > "Thread-8" prio=10 tid=0x0000000043c01800 nid=0x1b59 waiting on condition
> > [0x0000000042359000..0x0000000042359a10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34bf7c0> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> > nager.java:479)
> >
> > "Thread-7" daemon prio=10 tid=0x00002aaac80f7800 nid=0x1b58 runnable
> > [0x000000004265c000..0x000000004265cd90]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.FileDispatcher.read0(Native Method)
> > at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> > at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> > at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> > at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> > - locked <0x00002aaab34c4d98> (a java.lang.Object)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> > nager.java:551)
> >
> > "Thread-6" daemon prio=10 tid=0x00002aaac80f5000 nid=0x1b57 waiting on
> > condition [0x000000004255b000..0x000000004255bd10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34c44b0> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> > nager.java:479)
> >
> > "Thread-5" daemon prio=10 tid=0x00002aaac80f3800 nid=0x1b56 runnable
> > [0x000000004245a000..0x000000004245ac90]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.FileDispatcher.read0(Native Method)
> > at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> > at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> > at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> > at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> > - locked <0x00002aaab34bf440> (a java.lang.Object)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> > nager.java:551)
> >
> > "Thread-2" daemon prio=10 tid=0x0000000043c00400 nid=0x1b53 waiting on
> > condition [0x0000000042157000..0x0000000042157b10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34c5438> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> > nager.java:479)
> >
> > "QuorumPeer:/0:0:0:0:0:0:0:0:2181" prio=10 tid=0x00002aaac80f2400
> nid=0x1b4f
> > runnable [0x0000000042056000..0x0000000042056a90]
> >    java.lang.Thread.State: RUNNABLE
> > at java.net.SocketInputStream.socketRead0(Native Method)
> > at java.net.SocketInputStream.read(SocketInputStream.java:129)
> > at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> > at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
> > - locked <0x00002aaab34da038> (a java.io.BufferedInputStream)
> > at java.io.DataInputStream.readInt(DataInputStream.java:370)
> > at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:64)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:
> > 65)
> > at
> >
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:109)
> > at
> org.apache.zookeeper.server.quorum.Follower.readPacket(Follower.java:109)
> > - locked <0x00002aaab34d9fe8> (a org.apache.jute.BinaryInputArchive)
> > at
> >
> org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:221)
> > at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:450)
> >
> > "WorkerReceiver Thread" daemon prio=10 tid=0x00002aaac80f1800 nid=0x1b4e
> > waiting on condition [0x0000000041f55000..0x0000000041f55a10]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34be738> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> > at
> >
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver
> > .run(FastLeaderElection.java:186)
> > at java.lang.Thread.run(Thread.java:619)
> >
> > "WorkerSender Thread" daemon prio=10 tid=0x00002aaac80f1000 nid=0x1b4d
> > waiting on condition [0x0000000041ae5000..0x0000000041ae5d90]
> >    java.lang.Thread.State: WAITING (parking)
> > at sun.misc.Unsafe.park(Native Method)
> > - parking to wait for  <0x00002aaab34be868> (a
> > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> > at
> >
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> > stractQueuedSynchronizer.java:1925)
> > at
> >
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> > at
> >
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.r
> > un(FastLeaderElection.java:287)
> > at java.lang.Thread.run(Thread.java:619)
> >
> > "Thread-1" prio=10 tid=0x00002aaac80ec800 nid=0x1b4a runnable
> > [0x00000000419e4000..0x00000000419e4d10]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
> > at
> >
> sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145)
> > - locked <0x00002aaab34bcf70> (a java.lang.Object)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxMana
> > ger.java:413)
> >
> > "NIOServerCxn.Factory:2181" daemon prio=10 tid=0x00002aaac8066c00
> nid=0x1af6
> > runnable [0x0000000041333000..0x0000000041333c90]
> >    java.lang.Thread.State: RUNNABLE
> > at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
> > at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:184)
> > at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)
> > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
> > - locked <0x00002aaab3489ae8> (a sun.nio.ch.Util$1)
> > - locked <0x00002aaab3489ad0> (a java.util.Collections$UnmodifiableSet)
> > - locked <0x00002aaab34893f8> (a sun.nio.ch.EPollSelectorImpl)
> > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
> > at
> >
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:142)
> >
> > "RMI TCP Accept-0" daemon prio=10 tid=0x00002aaac805d800 nid=0x1af4
> runnable
> > [0x0000000041131000..0x0000000041131b90]
> >    java.lang.Thread.State: RUNNABLE
> > at java.net.PlainSocketImpl.socketAccept(Native Method)
> > at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
> > - locked <0x00002aaab3488238> (a java.net.SocksSocketImpl)
> > at java.net.ServerSocket.implAccept(ServerSocket.java:453)
> > at java.net.ServerSocket.accept(ServerSocket.java:421)
> > at
> >
> sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.j
> > ava:369)
> > at
> sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
> > at java.lang.Thread.run(Thread.java:619)
> >
> > "Low Memory Detector" daemon prio=10 tid=0x000000004398dc00 nid=0x1af3
> > runnable [0x0000000000000000..0x0000000000000000]
> >    java.lang.Thread.State: RUNNABLE
> >
> > "CompilerThread1" daemon prio=10 tid=0x000000004398b400 nid=0x1af2
> waiting
> > on condition [0x0000000000000000..0x0000000040f2ea80]
> >    java.lang.Thread.State: RUNNABLE
> >
> > "CompilerThread0" daemon prio=10 tid=0x0000000043989800 nid=0x1af1
> waiting
> > on condition [0x0000000000000000..0x0000000040e2da10]
> >    java.lang.Thread.State: RUNNABLE
> >
> > "Signal Dispatcher" daemon prio=10 tid=0x0000000043988000 nid=0x1af0
> > runnable [0x0000000000000000..0x0000000040d2da20]
> >    java.lang.Thread.State: RUNNABLE
> >
> > "Finalizer" daemon prio=10 tid=0x0000000043964c00 nid=0x1aef in
> > Object.wait() [0x0000000041e54000..0x0000000041e54d10]
> >    java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
> > - locked <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
> > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
> >
> > "Reference Handler" daemon prio=10 tid=0x0000000043964000 nid=0x1aee in
> > Object.wait() [0x0000000041d53000..0x0000000041d53c90]
> >    java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
> > at java.lang.Object.wait(Object.java:485)
> > at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
> > - locked <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
> >
> > "main" prio=10 tid=0x00000000438ae800 nid=0x1ae4 in Object.wait()
> > [0x0000000040406000..0x0000000040406ed0]
> >    java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0x00002aaab3488a38> (a
> > org.apache.zookeeper.server.quorum.QuorumPeer)
> > at java.lang.Thread.join(Thread.java:1143)
> > - locked <0x00002aaab3488a38> (a
> > org.apache.zookeeper.server.quorum.QuorumPeer)
> > at java.lang.Thread.join(Thread.java:1196)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runPeer(QuorumPeerMain.java:
> > 116)
> > at
> >
> org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:86)
> >
> > "VM Thread" prio=10 tid=0x000000004395f400 nid=0x1aed runnable
> >
> > "GC task thread#0 (ParallelGC)" prio=10 tid=0x00000000438b9000 nid=0x1ae5
> > runnable
> >
> > "GC task thread#1 (ParallelGC)" prio=10 tid=0x00000000438ba000 nid=0x1ae6
> > runnable
> >
> > "GC task thread#2 (ParallelGC)" prio=10 tid=0x00000000438bb400 nid=0x1ae7
> > runnable
> >
> > "GC task thread#3 (ParallelGC)" prio=10 tid=0x00000000438bc800 nid=0x1ae8
> > runnable
> >
> > "GC task thread#4 (ParallelGC)" prio=10 tid=0x00000000438bdc00 nid=0x1ae9
> > runnable
> >
> > "GC task thread#5 (ParallelGC)" prio=10 tid=0x00000000438bf000 nid=0x1aea
> > runnable
> >
> > "GC task thread#6 (ParallelGC)" prio=10 tid=0x00000000438c0400 nid=0x1aeb
> > runnable
> >
> > "GC task thread#7 (ParallelGC)" prio=10 tid=0x00000000438c1800 nid=0x1aec
> > runnable
> >
> > "VM Periodic Task Thread" prio=10 tid=0x00002aaac8065800 nid=0x1af5
> waiting
> > on condition
> >
> > JNI global references: 895
> >
> >
> > On Tue, Jun 2, 2009 at 1:22 PM, Benjamin Reed <br...@yahoo-inc.com>
> wrote:
> >
> >> can you attach the jstack output? it seems to be missing from your
> email.
> >>
> >> ben
> >>
> >>
> >> Satish Bhatti wrote:
> >>
> >>> I am running a 5 node ZooKeeper cluster and I noticed that one of them
> has
> >>> very high CPU usage:
> >>>
> >>>  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+
> COMMAND
> >>>  6883  infact       22   0   725m  41m  4188 S   95       0.5
> >>>  5671:54  java
> >>>
> >>> It is not "doing anything" application-wise at this point, so I was
> >>> wondering why the heck it's using up so much CPU!  I have attached a
> jstack
> >>> logfile to this email.
> >>>
> >>> Satish
> >>>
> >>>
> >>
>
>

Re: ZooKeeper heavy CPU utilisation

Posted by Ted Dunning <te...@gmail.com>.
Mailing lists like this often strip attachments.

On Tue, Jun 2, 2009 at 1:29 PM, Satish Bhatti <ct...@gmail.com> wrote:

> Hey Ben,
> Strange you didn't get the attachment, my gmail is showing the paper clip
> thingy for that message.  ANyway, I have pasted the whole jstack output
> into
> this email, since it's pretty small.
>
> Satish
>
> 2009-06-02 11:56:26
> Full thread dump Java HotSpot(TM) 64-Bit Server VM (1.6.0_03-b05 mixed
> mode):
>
> "Attach Listener" daemon prio=10 tid=0x0000000043e71800 nid=0x5566 waiting
> on condition [0x0000000000000000..0x0000000000000000]
>   java.lang.Thread.State: RUNNABLE
>
> "SyncThread:4" prio=10 tid=0x00002aaac8274800 nid=0x1ced waiting on
> condition [0x0000000042d63000..0x0000000042d63c10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34e44d8> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> at
>
> org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:71)
>
> "FollowerRequestProcessor:4" prio=10 tid=0x00002aaac8273c00 nid=0x1cec
> waiting on condition [0x0000000042b61000..0x0000000042b61b90]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34e4648> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> at
>
> org.apache.zookeeper.server.quorum.FollowerRequestProcessor.run(FollowerRequestProcessor.java:58)
>
> "CommitProcessor:4" prio=10 tid=0x00002aaac8150400 nid=0x1ceb in
> Object.wait() [0x0000000042c62000..0x0000000042c62b10]
>   java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab34e46f0> (a
> org.apache.zookeeper.server.quorum.CommitProcessor)
> at java.lang.Object.wait(Object.java:485)
> at
>
> org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:80)
> - locked <0x00002aaab34e46f0> (a
> org.apache.zookeeper.server.quorum.CommitProcessor)
>
> "Thread-13" daemon prio=10 tid=0x00002aaac80f9800 nid=0x1b5e runnable
> [0x0000000042a60000..0x0000000042a60c90]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34bf5c8> (a java.lang.Object)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)
>
> "Thread-12" daemon prio=10 tid=0x00002aaac80f8c00 nid=0x1b5d waiting on
> condition [0x0000000042258000..0x0000000042258c10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34bf7c0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)
>
> "Thread-11" prio=10 tid=0x0000000043d22800 nid=0x1b5c runnable
> [0x000000004295f000..0x000000004295fb90]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34bf9a8> (a java.lang.Object)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)
>
> "Thread-10" prio=10 tid=0x0000000043d21400 nid=0x1b5b waiting on condition
> [0x000000004285e000..0x000000004285eb10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34bfbf8> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)
>
> "Thread-9" prio=10 tid=0x0000000043d1d800 nid=0x1b5a runnable
> [0x000000004275d000..0x000000004275da90]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34c06c8> (a java.lang.Object)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)
>
> "Thread-8" prio=10 tid=0x0000000043c01800 nid=0x1b59 waiting on condition
> [0x0000000042359000..0x0000000042359a10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34bf7c0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)
>
> "Thread-7" daemon prio=10 tid=0x00002aaac80f7800 nid=0x1b58 runnable
> [0x000000004265c000..0x000000004265cd90]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34c4d98> (a java.lang.Object)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)
>
> "Thread-6" daemon prio=10 tid=0x00002aaac80f5000 nid=0x1b57 waiting on
> condition [0x000000004255b000..0x000000004255bd10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34c44b0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)
>
> "Thread-5" daemon prio=10 tid=0x00002aaac80f3800 nid=0x1b56 runnable
> [0x000000004245a000..0x000000004245ac90]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34bf440> (a java.lang.Object)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)
>
> "Thread-2" daemon prio=10 tid=0x0000000043c00400 nid=0x1b53 waiting on
> condition [0x0000000042157000..0x0000000042157b10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34c5438> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)
>
> "QuorumPeer:/0:0:0:0:0:0:0:0:2181" prio=10 tid=0x00002aaac80f2400
> nid=0x1b4f
> runnable [0x0000000042056000..0x0000000042056a90]
>   java.lang.Thread.State: RUNNABLE
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:129)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
> - locked <0x00002aaab34da038> (a java.io.BufferedInputStream)
> at java.io.DataInputStream.readInt(DataInputStream.java:370)
> at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:64)
> at
>
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:65)
> at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:109)
> at
> org.apache.zookeeper.server.quorum.Follower.readPacket(Follower.java:109)
> - locked <0x00002aaab34d9fe8> (a org.apache.jute.BinaryInputArchive)
> at
> org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:221)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:450)
>
> "WorkerReceiver Thread" daemon prio=10 tid=0x00002aaac80f1800 nid=0x1b4e
> waiting on condition [0x0000000041f55000..0x0000000041f55a10]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34be738> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
>
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:186)
> at java.lang.Thread.run(Thread.java:619)
>
> "WorkerSender Thread" daemon prio=10 tid=0x00002aaac80f1000 nid=0x1b4d
> waiting on condition [0x0000000041ae5000..0x0000000041ae5d90]
>   java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34be868> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
>
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> at
>
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:287)
> at java.lang.Thread.run(Thread.java:619)
>
> "Thread-1" prio=10 tid=0x00002aaac80ec800 nid=0x1b4a runnable
> [0x00000000419e4000..0x00000000419e4d10]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
> at
> sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145)
> - locked <0x00002aaab34bcf70> (a java.lang.Object)
> at
>
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:413)
>
> "NIOServerCxn.Factory:2181" daemon prio=10 tid=0x00002aaac8066c00
> nid=0x1af6
> runnable [0x0000000041333000..0x0000000041333c90]
>   java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
> at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:184)
> at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)
> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
> - locked <0x00002aaab3489ae8> (a sun.nio.ch.Util$1)
> - locked <0x00002aaab3489ad0> (a java.util.Collections$UnmodifiableSet)
> - locked <0x00002aaab34893f8> (a sun.nio.ch.EPollSelectorImpl)
> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
> at
>
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:142)
>
> "RMI TCP Accept-0" daemon prio=10 tid=0x00002aaac805d800 nid=0x1af4
> runnable
> [0x0000000041131000..0x0000000041131b90]
>   java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketAccept(Native Method)
> at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
> - locked <0x00002aaab3488238> (a java.net.SocksSocketImpl)
> at java.net.ServerSocket.implAccept(ServerSocket.java:453)
> at java.net.ServerSocket.accept(ServerSocket.java:421)
> at
>
> sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
> at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
> at java.lang.Thread.run(Thread.java:619)
>
> "Low Memory Detector" daemon prio=10 tid=0x000000004398dc00 nid=0x1af3
> runnable [0x0000000000000000..0x0000000000000000]
>   java.lang.Thread.State: RUNNABLE
>
> "CompilerThread1" daemon prio=10 tid=0x000000004398b400 nid=0x1af2 waiting
> on condition [0x0000000000000000..0x0000000040f2ea80]
>   java.lang.Thread.State: RUNNABLE
>
> "CompilerThread0" daemon prio=10 tid=0x0000000043989800 nid=0x1af1 waiting
> on condition [0x0000000000000000..0x0000000040e2da10]
>   java.lang.Thread.State: RUNNABLE
>
> "Signal Dispatcher" daemon prio=10 tid=0x0000000043988000 nid=0x1af0
> runnable [0x0000000000000000..0x0000000040d2da20]
>   java.lang.Thread.State: RUNNABLE
>
> "Finalizer" daemon prio=10 tid=0x0000000043964c00 nid=0x1aef in
> Object.wait() [0x0000000041e54000..0x0000000041e54d10]
>   java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
> - locked <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
> at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
>
> "Reference Handler" daemon prio=10 tid=0x0000000043964000 nid=0x1aee in
> Object.wait() [0x0000000041d53000..0x0000000041d53c90]
>   java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
> at java.lang.Object.wait(Object.java:485)
> at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
> - locked <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
>
> "main" prio=10 tid=0x00000000438ae800 nid=0x1ae4 in Object.wait()
> [0x0000000040406000..0x0000000040406ed0]
>   java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab3488a38> (a
> org.apache.zookeeper.server.quorum.QuorumPeer)
> at java.lang.Thread.join(Thread.java:1143)
> - locked <0x00002aaab3488a38> (a
> org.apache.zookeeper.server.quorum.QuorumPeer)
> at java.lang.Thread.join(Thread.java:1196)
> at
>
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runPeer(QuorumPeerMain.java:116)
> at
>
> org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:86)
>
> "VM Thread" prio=10 tid=0x000000004395f400 nid=0x1aed runnable
>
> "GC task thread#0 (ParallelGC)" prio=10 tid=0x00000000438b9000 nid=0x1ae5
> runnable
>
> "GC task thread#1 (ParallelGC)" prio=10 tid=0x00000000438ba000 nid=0x1ae6
> runnable
>
> "GC task thread#2 (ParallelGC)" prio=10 tid=0x00000000438bb400 nid=0x1ae7
> runnable
>
> "GC task thread#3 (ParallelGC)" prio=10 tid=0x00000000438bc800 nid=0x1ae8
> runnable
>
> "GC task thread#4 (ParallelGC)" prio=10 tid=0x00000000438bdc00 nid=0x1ae9
> runnable
>
> "GC task thread#5 (ParallelGC)" prio=10 tid=0x00000000438bf000 nid=0x1aea
> runnable
>
> "GC task thread#6 (ParallelGC)" prio=10 tid=0x00000000438c0400 nid=0x1aeb
> runnable
>
> "GC task thread#7 (ParallelGC)" prio=10 tid=0x00000000438c1800 nid=0x1aec
> runnable
>
> "VM Periodic Task Thread" prio=10 tid=0x00002aaac8065800 nid=0x1af5 waiting
> on condition
>
> JNI global references: 895
>
>
> On Tue, Jun 2, 2009 at 1:22 PM, Benjamin Reed <br...@yahoo-inc.com> wrote:
>
> > can you attach the jstack output? it seems to be missing from your email.
> >
> > ben
> >
> >
> > Satish Bhatti wrote:
> >
> >> I am running a 5 node ZooKeeper cluster and I noticed that one of them
> has
> >> very high CPU usage:
> >>
> >>  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND
> >>  6883  infact       22   0   725m  41m  4188 S   95       0.5
> >>  5671:54  java
> >>
> >> It is not "doing anything" application-wise at this point, so I was
> >> wondering why the heck it's using up so much CPU!  I have attached a
> jstack
> >> logfile to this email.
> >>
> >> Satish
> >>
> >>
> >
>



-- 
Ted Dunning, CTO
DeepDyve

111 West Evelyn Ave. Ste. 202
Sunnyvale, CA 94086
http://www.deepdyve.com
858-414-0013 (m)
408-773-0220 (fax)

Re: ZooKeeper heavy CPU utilisation

Posted by Mahadev Konar <ma...@yahoo-inc.com>.
Hi Satish,
  Can you attach this trace to a jira? Please open one for this. Also, can
you do the following -

For all the threads for the zookeeper server you are seeing the problem on,

Can you do an strace on all the threads and see which thread is spinning?

Also, can you upload the configs of the servers to the jira that you create?

mahadev


On 6/2/09 1:29 PM, "Satish Bhatti" <ct...@gmail.com> wrote:

> Hey Ben,
> Strange you didn't get the attachment, my gmail is showing the paper clip
> thingy for that message.  ANyway, I have pasted the whole jstack output into
> this email, since it's pretty small.
> 
> Satish
> 
> 2009-06-02 11:56:26
> Full thread dump Java HotSpot(TM) 64-Bit Server VM (1.6.0_03-b05 mixed
> mode):
> 
> "Attach Listener" daemon prio=10 tid=0x0000000043e71800 nid=0x5566 waiting
> on condition [0x0000000000000000..0x0000000000000000]
>    java.lang.Thread.State: RUNNABLE
> 
> "SyncThread:4" prio=10 tid=0x00002aaac8274800 nid=0x1ced waiting on
> condition [0x0000000042d63000..0x0000000042d63c10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34e44d8> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> at
> org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java
> :71)
> 
> "FollowerRequestProcessor:4" prio=10 tid=0x00002aaac8273c00 nid=0x1cec
> waiting on condition [0x0000000042b61000..0x0000000042b61b90]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34e4648> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> at
> org.apache.zookeeper.server.quorum.FollowerRequestProcessor.run(FollowerReques
> tProcessor.java:58)
> 
> "CommitProcessor:4" prio=10 tid=0x00002aaac8150400 nid=0x1ceb in
> Object.wait() [0x0000000042c62000..0x0000000042c62b10]
>    java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab34e46f0> (a
> org.apache.zookeeper.server.quorum.CommitProcessor)
> at java.lang.Object.wait(Object.java:485)
> at
> 
org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:80>
)
> - locked <0x00002aaab34e46f0> (a
> org.apache.zookeeper.server.quorum.CommitProcessor)
> 
> "Thread-13" daemon prio=10 tid=0x00002aaac80f9800 nid=0x1b5e runnable
> [0x0000000042a60000..0x0000000042a60c90]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34bf5c8> (a java.lang.Object)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> nager.java:551)
> 
> "Thread-12" daemon prio=10 tid=0x00002aaac80f8c00 nid=0x1b5d waiting on
> condition [0x0000000042258000..0x0000000042258c10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34bf7c0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> nager.java:479)
> 
> "Thread-11" prio=10 tid=0x0000000043d22800 nid=0x1b5c runnable
> [0x000000004295f000..0x000000004295fb90]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34bf9a8> (a java.lang.Object)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> nager.java:551)
> 
> "Thread-10" prio=10 tid=0x0000000043d21400 nid=0x1b5b waiting on condition
> [0x000000004285e000..0x000000004285eb10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34bfbf8> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> nager.java:479)
> 
> "Thread-9" prio=10 tid=0x0000000043d1d800 nid=0x1b5a runnable
> [0x000000004275d000..0x000000004275da90]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34c06c8> (a java.lang.Object)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> nager.java:551)
> 
> "Thread-8" prio=10 tid=0x0000000043c01800 nid=0x1b59 waiting on condition
> [0x0000000042359000..0x0000000042359a10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34bf7c0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> nager.java:479)
> 
> "Thread-7" daemon prio=10 tid=0x00002aaac80f7800 nid=0x1b58 runnable
> [0x000000004265c000..0x000000004265cd90]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34c4d98> (a java.lang.Object)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> nager.java:551)
> 
> "Thread-6" daemon prio=10 tid=0x00002aaac80f5000 nid=0x1b57 waiting on
> condition [0x000000004255b000..0x000000004255bd10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34c44b0> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> nager.java:479)
> 
> "Thread-5" daemon prio=10 tid=0x00002aaac80f3800 nid=0x1b56 runnable
> [0x000000004245a000..0x000000004245ac90]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.FileDispatcher.read0(Native Method)
> at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
> at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
> at sun.nio.ch.IOUtil.read(IOUtil.java:206)
> at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
> - locked <0x00002aaab34bf440> (a java.lang.Object)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxMa
> nager.java:551)
> 
> "Thread-2" daemon prio=10 tid=0x0000000043c00400 nid=0x1b53 waiting on
> condition [0x0000000042157000..0x0000000042157b10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34c5438> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxMa
> nager.java:479)
> 
> "QuorumPeer:/0:0:0:0:0:0:0:0:2181" prio=10 tid=0x00002aaac80f2400 nid=0x1b4f
> runnable [0x0000000042056000..0x0000000042056a90]
>    java.lang.Thread.State: RUNNABLE
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:129)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
> - locked <0x00002aaab34da038> (a java.io.BufferedInputStream)
> at java.io.DataInputStream.readInt(DataInputStream.java:370)
> at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:64)
> at
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:
> 65)
> at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:109)
> at org.apache.zookeeper.server.quorum.Follower.readPacket(Follower.java:109)
> - locked <0x00002aaab34d9fe8> (a org.apache.jute.BinaryInputArchive)
> at
> org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:221)
> at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:450)
> 
> "WorkerReceiver Thread" daemon prio=10 tid=0x00002aaac80f1800 nid=0x1b4e
> waiting on condition [0x0000000041f55000..0x0000000041f55a10]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34be738> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver
> .run(FastLeaderElection.java:186)
> at java.lang.Thread.run(Thread.java:619)
> 
> "WorkerSender Thread" daemon prio=10 tid=0x00002aaac80f1000 nid=0x1b4d
> waiting on condition [0x0000000041ae5000..0x0000000041ae5d90]
>    java.lang.Thread.State: WAITING (parking)
> at sun.misc.Unsafe.park(Native Method)
> - parking to wait for  <0x00002aaab34be868> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
> at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Ab
> stractQueuedSynchronizer.java:1925)
> at
> java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
> at
> org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.r
> un(FastLeaderElection.java:287)
> at java.lang.Thread.run(Thread.java:619)
> 
> "Thread-1" prio=10 tid=0x00002aaac80ec800 nid=0x1b4a runnable
> [0x00000000419e4000..0x00000000419e4d10]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
> at
> sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145)
> - locked <0x00002aaab34bcf70> (a java.lang.Object)
> at
> org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxMana
> ger.java:413)
> 
> "NIOServerCxn.Factory:2181" daemon prio=10 tid=0x00002aaac8066c00 nid=0x1af6
> runnable [0x0000000041333000..0x0000000041333c90]
>    java.lang.Thread.State: RUNNABLE
> at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
> at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:184)
> at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)
> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
> - locked <0x00002aaab3489ae8> (a sun.nio.ch.Util$1)
> - locked <0x00002aaab3489ad0> (a java.util.Collections$UnmodifiableSet)
> - locked <0x00002aaab34893f8> (a sun.nio.ch.EPollSelectorImpl)
> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
> at
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:142)
> 
> "RMI TCP Accept-0" daemon prio=10 tid=0x00002aaac805d800 nid=0x1af4 runnable
> [0x0000000041131000..0x0000000041131b90]
>    java.lang.Thread.State: RUNNABLE
> at java.net.PlainSocketImpl.socketAccept(Native Method)
> at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
> - locked <0x00002aaab3488238> (a java.net.SocksSocketImpl)
> at java.net.ServerSocket.implAccept(ServerSocket.java:453)
> at java.net.ServerSocket.accept(ServerSocket.java:421)
> at
> sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.j
> ava:369)
> at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
> at java.lang.Thread.run(Thread.java:619)
> 
> "Low Memory Detector" daemon prio=10 tid=0x000000004398dc00 nid=0x1af3
> runnable [0x0000000000000000..0x0000000000000000]
>    java.lang.Thread.State: RUNNABLE
> 
> "CompilerThread1" daemon prio=10 tid=0x000000004398b400 nid=0x1af2 waiting
> on condition [0x0000000000000000..0x0000000040f2ea80]
>    java.lang.Thread.State: RUNNABLE
> 
> "CompilerThread0" daemon prio=10 tid=0x0000000043989800 nid=0x1af1 waiting
> on condition [0x0000000000000000..0x0000000040e2da10]
>    java.lang.Thread.State: RUNNABLE
> 
> "Signal Dispatcher" daemon prio=10 tid=0x0000000043988000 nid=0x1af0
> runnable [0x0000000000000000..0x0000000040d2da20]
>    java.lang.Thread.State: RUNNABLE
> 
> "Finalizer" daemon prio=10 tid=0x0000000043964c00 nid=0x1aef in
> Object.wait() [0x0000000041e54000..0x0000000041e54d10]
>    java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
> - locked <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
> at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
> at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)
> 
> "Reference Handler" daemon prio=10 tid=0x0000000043964000 nid=0x1aee in
> Object.wait() [0x0000000041d53000..0x0000000041d53c90]
>    java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
> at java.lang.Object.wait(Object.java:485)
> at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
> - locked <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
> 
> "main" prio=10 tid=0x00000000438ae800 nid=0x1ae4 in Object.wait()
> [0x0000000040406000..0x0000000040406ed0]
>    java.lang.Thread.State: WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on <0x00002aaab3488a38> (a
> org.apache.zookeeper.server.quorum.QuorumPeer)
> at java.lang.Thread.join(Thread.java:1143)
> - locked <0x00002aaab3488a38> (a
> org.apache.zookeeper.server.quorum.QuorumPeer)
> at java.lang.Thread.join(Thread.java:1196)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.runPeer(QuorumPeerMain.java:
> 116)
> at
> org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:86)
> 
> "VM Thread" prio=10 tid=0x000000004395f400 nid=0x1aed runnable
> 
> "GC task thread#0 (ParallelGC)" prio=10 tid=0x00000000438b9000 nid=0x1ae5
> runnable
> 
> "GC task thread#1 (ParallelGC)" prio=10 tid=0x00000000438ba000 nid=0x1ae6
> runnable
> 
> "GC task thread#2 (ParallelGC)" prio=10 tid=0x00000000438bb400 nid=0x1ae7
> runnable
> 
> "GC task thread#3 (ParallelGC)" prio=10 tid=0x00000000438bc800 nid=0x1ae8
> runnable
> 
> "GC task thread#4 (ParallelGC)" prio=10 tid=0x00000000438bdc00 nid=0x1ae9
> runnable
> 
> "GC task thread#5 (ParallelGC)" prio=10 tid=0x00000000438bf000 nid=0x1aea
> runnable
> 
> "GC task thread#6 (ParallelGC)" prio=10 tid=0x00000000438c0400 nid=0x1aeb
> runnable
> 
> "GC task thread#7 (ParallelGC)" prio=10 tid=0x00000000438c1800 nid=0x1aec
> runnable
> 
> "VM Periodic Task Thread" prio=10 tid=0x00002aaac8065800 nid=0x1af5 waiting
> on condition
> 
> JNI global references: 895
> 
> 
> On Tue, Jun 2, 2009 at 1:22 PM, Benjamin Reed <br...@yahoo-inc.com> wrote:
> 
>> can you attach the jstack output? it seems to be missing from your email.
>> 
>> ben
>> 
>> 
>> Satish Bhatti wrote:
>> 
>>> I am running a 5 node ZooKeeper cluster and I noticed that one of them has
>>> very high CPU usage:
>>> 
>>>  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND
>>>  6883  infact       22   0   725m  41m  4188 S   95       0.5
>>>  5671:54  java
>>> 
>>> It is not "doing anything" application-wise at this point, so I was
>>> wondering why the heck it's using up so much CPU!  I have attached a jstack
>>> logfile to this email.
>>> 
>>> Satish
>>> 
>>> 
>> 


Re: ZooKeeper heavy CPU utilisation

Posted by Satish Bhatti <ct...@gmail.com>.
Hey Ben,
Strange you didn't get the attachment, my gmail is showing the paper clip
thingy for that message.  ANyway, I have pasted the whole jstack output into
this email, since it's pretty small.

Satish

2009-06-02 11:56:26
Full thread dump Java HotSpot(TM) 64-Bit Server VM (1.6.0_03-b05 mixed
mode):

"Attach Listener" daemon prio=10 tid=0x0000000043e71800 nid=0x5566 waiting
on condition [0x0000000000000000..0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"SyncThread:4" prio=10 tid=0x00002aaac8274800 nid=0x1ced waiting on
condition [0x0000000042d63000..0x0000000042d63c10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34e44d8> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
at
org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:71)

"FollowerRequestProcessor:4" prio=10 tid=0x00002aaac8273c00 nid=0x1cec
waiting on condition [0x0000000042b61000..0x0000000042b61b90]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34e4648> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
at
org.apache.zookeeper.server.quorum.FollowerRequestProcessor.run(FollowerRequestProcessor.java:58)

"CommitProcessor:4" prio=10 tid=0x00002aaac8150400 nid=0x1ceb in
Object.wait() [0x0000000042c62000..0x0000000042c62b10]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00002aaab34e46f0> (a
org.apache.zookeeper.server.quorum.CommitProcessor)
at java.lang.Object.wait(Object.java:485)
at
org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:80)
- locked <0x00002aaab34e46f0> (a
org.apache.zookeeper.server.quorum.CommitProcessor)

"Thread-13" daemon prio=10 tid=0x00002aaac80f9800 nid=0x1b5e runnable
[0x0000000042a60000..0x0000000042a60c90]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
at sun.nio.ch.IOUtil.read(IOUtil.java:206)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
- locked <0x00002aaab34bf5c8> (a java.lang.Object)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)

"Thread-12" daemon prio=10 tid=0x00002aaac80f8c00 nid=0x1b5d waiting on
condition [0x0000000042258000..0x0000000042258c10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34bf7c0> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)

"Thread-11" prio=10 tid=0x0000000043d22800 nid=0x1b5c runnable
[0x000000004295f000..0x000000004295fb90]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
at sun.nio.ch.IOUtil.read(IOUtil.java:206)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
- locked <0x00002aaab34bf9a8> (a java.lang.Object)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)

"Thread-10" prio=10 tid=0x0000000043d21400 nid=0x1b5b waiting on condition
[0x000000004285e000..0x000000004285eb10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34bfbf8> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)

"Thread-9" prio=10 tid=0x0000000043d1d800 nid=0x1b5a runnable
[0x000000004275d000..0x000000004275da90]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
at sun.nio.ch.IOUtil.read(IOUtil.java:206)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
- locked <0x00002aaab34c06c8> (a java.lang.Object)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)

"Thread-8" prio=10 tid=0x0000000043c01800 nid=0x1b59 waiting on condition
[0x0000000042359000..0x0000000042359a10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34bf7c0> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)

"Thread-7" daemon prio=10 tid=0x00002aaac80f7800 nid=0x1b58 runnable
[0x000000004265c000..0x000000004265cd90]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
at sun.nio.ch.IOUtil.read(IOUtil.java:206)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
- locked <0x00002aaab34c4d98> (a java.lang.Object)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)

"Thread-6" daemon prio=10 tid=0x00002aaac80f5000 nid=0x1b57 waiting on
condition [0x000000004255b000..0x000000004255bd10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34c44b0> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)

"Thread-5" daemon prio=10 tid=0x00002aaac80f3800 nid=0x1b56 runnable
[0x000000004245a000..0x000000004245ac90]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
at sun.nio.ch.IOUtil.read(IOUtil.java:206)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:236)
- locked <0x00002aaab34bf440> (a java.lang.Object)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:551)

"Thread-2" daemon prio=10 tid=0x0000000043c00400 nid=0x1b53 waiting on
condition [0x0000000042157000..0x0000000042157b10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34c5438> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:479)

"QuorumPeer:/0:0:0:0:0:0:0:0:2181" prio=10 tid=0x00002aaac80f2400 nid=0x1b4f
runnable [0x0000000042056000..0x0000000042056a90]
   java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
- locked <0x00002aaab34da038> (a java.io.BufferedInputStream)
at java.io.DataInputStream.readInt(DataInputStream.java:370)
at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:64)
at
org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:65)
at
org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:109)
at org.apache.zookeeper.server.quorum.Follower.readPacket(Follower.java:109)
- locked <0x00002aaab34d9fe8> (a org.apache.jute.BinaryInputArchive)
at
org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:221)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:450)

"WorkerReceiver Thread" daemon prio=10 tid=0x00002aaac80f1800 nid=0x1b4e
waiting on condition [0x0000000041f55000..0x0000000041f55a10]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34be738> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:317)
at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerReceiver.run(FastLeaderElection.java:186)
at java.lang.Thread.run(Thread.java:619)

"WorkerSender Thread" daemon prio=10 tid=0x00002aaac80f1000 nid=0x1b4d
waiting on condition [0x0000000041ae5000..0x0000000041ae5d90]
   java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <0x00002aaab34be868> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:358)
at
org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:287)
at java.lang.Thread.run(Thread.java:619)

"Thread-1" prio=10 tid=0x00002aaac80ec800 nid=0x1b4a runnable
[0x00000000419e4000..0x00000000419e4d10]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
at
sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:145)
- locked <0x00002aaab34bcf70> (a java.lang.Object)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:413)

"NIOServerCxn.Factory:2181" daemon prio=10 tid=0x00002aaac8066c00 nid=0x1af6
runnable [0x0000000041333000..0x0000000041333c90]
   java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:184)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
- locked <0x00002aaab3489ae8> (a sun.nio.ch.Util$1)
- locked <0x00002aaab3489ad0> (a java.util.Collections$UnmodifiableSet)
- locked <0x00002aaab34893f8> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:80)
at
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:142)

"RMI TCP Accept-0" daemon prio=10 tid=0x00002aaac805d800 nid=0x1af4 runnable
[0x0000000041131000..0x0000000041131b90]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
- locked <0x00002aaab3488238> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:453)
at java.net.ServerSocket.accept(ServerSocket.java:421)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:619)

"Low Memory Detector" daemon prio=10 tid=0x000000004398dc00 nid=0x1af3
runnable [0x0000000000000000..0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=10 tid=0x000000004398b400 nid=0x1af2 waiting
on condition [0x0000000000000000..0x0000000040f2ea80]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x0000000043989800 nid=0x1af1 waiting
on condition [0x0000000000000000..0x0000000040e2da10]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x0000000043988000 nid=0x1af0
runnable [0x0000000000000000..0x0000000040d2da20]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x0000000043964c00 nid=0x1aef in
Object.wait() [0x0000000041e54000..0x0000000041e54d10]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x00002aaab34b1a18> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x0000000043964000 nid=0x1aee in
Object.wait() [0x0000000041d53000..0x0000000041d53c90]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x00002aaab349abe0> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x00000000438ae800 nid=0x1ae4 in Object.wait()
[0x0000000040406000..0x0000000040406ed0]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00002aaab3488a38> (a
org.apache.zookeeper.server.quorum.QuorumPeer)
at java.lang.Thread.join(Thread.java:1143)
- locked <0x00002aaab3488a38> (a
org.apache.zookeeper.server.quorum.QuorumPeer)
at java.lang.Thread.join(Thread.java:1196)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.runPeer(QuorumPeerMain.java:116)
at
org.apache.zookeeper.server.quorum.QuorumPeerMain.main(QuorumPeerMain.java:86)

"VM Thread" prio=10 tid=0x000000004395f400 nid=0x1aed runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00000000438b9000 nid=0x1ae5
runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00000000438ba000 nid=0x1ae6
runnable

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00000000438bb400 nid=0x1ae7
runnable

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00000000438bc800 nid=0x1ae8
runnable

"GC task thread#4 (ParallelGC)" prio=10 tid=0x00000000438bdc00 nid=0x1ae9
runnable

"GC task thread#5 (ParallelGC)" prio=10 tid=0x00000000438bf000 nid=0x1aea
runnable

"GC task thread#6 (ParallelGC)" prio=10 tid=0x00000000438c0400 nid=0x1aeb
runnable

"GC task thread#7 (ParallelGC)" prio=10 tid=0x00000000438c1800 nid=0x1aec
runnable

"VM Periodic Task Thread" prio=10 tid=0x00002aaac8065800 nid=0x1af5 waiting
on condition

JNI global references: 895


On Tue, Jun 2, 2009 at 1:22 PM, Benjamin Reed <br...@yahoo-inc.com> wrote:

> can you attach the jstack output? it seems to be missing from your email.
>
> ben
>
>
> Satish Bhatti wrote:
>
>> I am running a 5 node ZooKeeper cluster and I noticed that one of them has
>> very high CPU usage:
>>
>>  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND
>>  6883  infact       22   0   725m  41m  4188 S   95       0.5
>>  5671:54  java
>>
>> It is not "doing anything" application-wise at this point, so I was
>> wondering why the heck it's using up so much CPU!  I have attached a jstack
>> logfile to this email.
>>
>> Satish
>>
>>
>

Re: ZooKeeper heavy CPU utilisation

Posted by Benjamin Reed <br...@yahoo-inc.com>.
can you attach the jstack output? it seems to be missing from your email.

ben

Satish Bhatti wrote:
> I am running a 5 node ZooKeeper cluster and I noticed that one of them 
> has very high CPU usage:
>
>  PID   USER      PR  NI  VIRT  RES  SHR S   %CPU %MEM    TIME+   COMMAND 
>  6883  infact       22   0   725m  41m  4188 S   95       0.5         
>  5671:54  java
>
> It is not "doing anything" application-wise at this point, so I was 
> wondering why the heck it's using up so much CPU!  I have attached a 
> jstack logfile to this email.
>
> Satish
>