zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Abraham Fine <af...@apache.org>
Subject Re: local call latency
Date Thu, 26 Oct 2017 22:51:07 GMT
There is nothing ZooKeeper specific, it's all standard JVM stuff.

This is a pretty good article detailing how to do it:
https://dzone.com/articles/understanding-garbage-collection-log

Of course you can always attach visualvm (https://visualvm.github.io) or
a profiler of your choice.

Let me know what you find or, better yet, post the logs so the community
can take a look.

Thanks,
Abe

On Thu, Oct 26, 2017, at 15:27, rammohan ganapavarapu wrote:
> That is what i was suspecting, how do i get gc logs? right now in my logs
> i
> dont see any gc related logging.
> 
> On Thu, Oct 26, 2017 at 2:08 PM, Abraham Fine <afine@apache.org> wrote:
> 
> > Another possibility... have you ruled out garbage collection related
> > pauses?
> >
> > Abe
> >
> > On Thu, Oct 26, 2017, at 13:57, rammohan ganapavarapu wrote:
> > > I was running ls command with in zkCli console from the same box.
> > >
> > > zkCli.sh --server localhost ls /node1, so no network involved.
> > >
> > > On Oct 26, 2017 12:37 PM, "Abraham Fine" <afine@apache.org> wrote:
> > >
> > > > Thanks for the jstack. I am not seeing anything unusual there.
> > > >
> > > > In your first message you mentioned that the command you executed is a
> > > > "local zk 'ls' command". By "local" do you mean that the command is
> > > > being executed from the same machine where the instance of zookeeper
> > you
> > > > are querying is running? It would be great to determine if the latency
> > > > is network related or more tied to zookeeper internals.
> > > >
> > > > Abe
> > > >
> > > > On Thu, Oct 26, 2017, at 10:57, rammohan ganapavarapu wrote:
> > > > > Abe,
> > > > >
> > > > > It is just 20kb file, not sure why its not able to deliver. I am
just
> > > > > copying the jstack here.
> > > > >
> > > > >
> > > > > ###
> > > > > > 2017-10-24 04:09:49
> > > > > > Full thread dump OpenJDK 64-Bit Server VM (25.101-b13 mixed
mode):
> > > > > > "Attach Listener" #758568 daemon prio=9 os_prio=0
> > > > tid=0x00007efbfc001000
> > > > > > nid=0x10cfb waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x00007efba0036000
> > > > nid=0x1a951
> > > > > > waiting on condition [0x00007efbbaeef000]
> > > > > >    java.lang.Thread.State: WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000006c55eced0> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.park(LockSupport.
> > java:175)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
> > > > > > at
> > > > > > java.util.concurrent.LinkedBlockingQueue.take(
> > > > LinkedBlockingQueue.java:442)
> > > > > > at
> > > > > > org.apache.zookeeper.server.SyncRequestProcessor.run(
> > > > SyncRequestProcessor.java:97)
> > > > > > "ObserverRequestProcessor:210" #73 prio=5 os_prio=0
> > > > tid=0x00007efba0035800
> > > > > > nid=0x1a950 waiting on condition [0x00007efbbaff0000]
> > > > > >    java.lang.Thread.State: WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000006c55ec2e8> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.park(LockSupport.
> > java:175)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
> > > > > > at
> > > > > > java.util.concurrent.LinkedBlockingQueue.take(
> > > > LinkedBlockingQueue.java:442)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.ObserverRequestProcessor.run(
> > > > ObserverRequestProcessor.java:66)
> > > > > > "CommitProcessor:210" #72 prio=5 os_prio=0 tid=0x00007efba004d800
> > > > > > nid=0x1a94f in Object.wait() [0x00007efbbb0f1000]
> > > > > >    java.lang.Thread.State: WAITING (on object monitor)
> > > > > > at java.lang.Object.wait(Native Method)
> > > > > > at java.lang.Object.wait(Object.java:502)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.CommitProcessor.run(
> > > > CommitProcessor.java:80)
> > > > > > - locked <0x00000006c55eb8e0> (a
> > > > > > org.apache.zookeeper.server.quorum.CommitProcessor)
> > > > > > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x00007efba8013000
> > > > > > nid=0x1a415 runnable [0x00007efbbb1f2000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > > > > at java.net.SocketInputStream.socketRead(SocketInputStream.
> > java:116)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:170)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:223)
> > > > > > at java.io.DataInputStream.readInt(DataInputStream.java:387)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > RecvWorker.run(
> > > > QuorumCnxManager.java:747)
> > > > > > "SendWorker:204" #39 daemon prio=5 os_prio=0 tid=0x00007efba8011000
> > > > > > nid=0x1a414 waiting on condition [0x00007efbbb2f3000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c018c938> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.ArrayBlockingQueue.poll(
> > > > ArrayBlockingQueue.java:418)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(
> > > > QuorumCnxManager.java:831)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.
> > > > access$500(QuorumCnxManager.java:62)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > SendWorker.run(
> > > > QuorumCnxManager.java:667)
> > > > > > "RecvWorker:203" #38 daemon prio=5 os_prio=0 tid=0x00007efba800f800
> > > > > > nid=0x1a413 runnable [0x00007efbbb3f4000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > > > > at java.net.SocketInputStream.socketRead(SocketInputStream.
> > java:116)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:170)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:223)
> > > > > > at java.io.DataInputStream.readInt(DataInputStream.java:387)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > RecvWorker.run(
> > > > QuorumCnxManager.java:747)
> > > > > > "SendWorker:203" #37 daemon prio=5 os_prio=0 tid=0x00007efba800d800
> > > > > > nid=0x1a412 waiting on condition [0x00007efbbb4f5000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c018bf00> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.ArrayBlockingQueue.poll(
> > > > ArrayBlockingQueue.java:418)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(
> > > > QuorumCnxManager.java:831)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.
> > > > access$500(QuorumCnxManager.java:62)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > SendWorker.run(
> > > > QuorumCnxManager.java:667)
> > > > > > "RecvWorker:202" #36 daemon prio=5 os_prio=0 tid=0x00007efba800c800
> > > > > > nid=0x1a411 runnable [0x00007efbbb6f7000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > > > > at java.net.SocketInputStream.socketRead(SocketInputStream.
> > java:116)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:170)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:223)
> > > > > > at java.io.DataInputStream.readInt(DataInputStream.java:387)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > RecvWorker.run(
> > > > QuorumCnxManager.java:747)
> > > > > > "SendWorker:202" #35 daemon prio=5 os_prio=0 tid=0x00007efba800b800
> > > > > > nid=0x1a410 waiting on condition [0x00007efbbb5f6000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c018b4c8> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.ArrayBlockingQueue.poll(
> > > > ArrayBlockingQueue.java:418)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(
> > > > QuorumCnxManager.java:831)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.
> > > > access$500(QuorumCnxManager.java:62)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > SendWorker.run(
> > > > QuorumCnxManager.java:667)
> > > > > > "RecvWorker:201" #32 daemon prio=5 os_prio=0 tid=0x00007efba8009800
> > > > > > nid=0x1a40d runnable [0x00007efbbb7f8000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > > > > at java.net.SocketInputStream.socketRead(SocketInputStream.
> > java:116)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:170)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:223)
> > > > > > at java.io.DataInputStream.readInt(DataInputStream.java:387)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > RecvWorker.run(
> > > > QuorumCnxManager.java:747)
> > > > > > "SendWorker:201" #31 daemon prio=5 os_prio=0 tid=0x00007efba8008800
> > > > > > nid=0x1a40c waiting on condition [0x00007efbbb8f9000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c016f830> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.ArrayBlockingQueue.poll(
> > > > ArrayBlockingQueue.java:418)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(
> > > > QuorumCnxManager.java:831)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.
> > > > access$500(QuorumCnxManager.java:62)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > SendWorker.run(
> > > > QuorumCnxManager.java:667)
> > > > > > "RecvWorker:200" #30 daemon prio=5 os_prio=0 tid=0x00007efba8008000
> > > > > > nid=0x1a3e5 runnable [0x00007efbbbafb000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > > > > at java.net.SocketInputStream.socketRead(SocketInputStream.
> > java:116)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:170)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:223)
> > > > > > at java.io.DataInputStream.readInt(DataInputStream.java:387)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > RecvWorker.run(
> > > > QuorumCnxManager.java:747)
> > > > > > "SendWorker:200" #29 daemon prio=5 os_prio=0 tid=0x00007efba8007000
> > > > > > nid=0x1a3e4 waiting on condition [0x00007efbbb9fa000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c016f910> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.ArrayBlockingQueue.poll(
> > > > ArrayBlockingQueue.java:418)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(
> > > > QuorumCnxManager.java:831)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.
> > > > access$500(QuorumCnxManager.java:62)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > SendWorker.run(
> > > > QuorumCnxManager.java:667)
> > > > > > "QuorumPeer[myid=210]/0:0:0:0:0:0:0:0:2181" #22 prio=5 os_prio=0
> > > > > > tid=0x00007efc6c2f7000 nid=0x1a3df runnable [0x00007efbbbbfc000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.SocketInputStream.socketRead0(Native Method)
> > > > > > at java.net.SocketInputStream.socketRead(SocketInputStream.
> > java:116)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:170)
> > > > > > at java.net.SocketInputStream.read(SocketInputStream.java:141)
> > > > > > at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
> > > > > > at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
> > > > > > - locked <0x00000005c01981b0> (a java.io.BufferedInputStream)
> > > > > > at java.io.DataInputStream.readInt(DataInputStream.java:387)
> > > > > > at org.apache.jute.BinaryInputArchive.readInt(
> > > > BinaryInputArchive.java:63)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumPacket.
> > > > deserialize(QuorumPacket.java:83)
> > > > > > at
> > > > > > org.apache.jute.BinaryInputArchive.readRecord(
> > > > BinaryInputArchive.java:108)
> > > > > > at org.apache.zookeeper.server.quorum.Learner.readPacket(
> > > > Learner.java:152)
> > > > > > - locked <0x00000005c019a228> (a org.apache.jute.
> > BinaryInputArchive)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.Observer.observeLeader(
> > > > Observer.java:75)
> > > > > > at org.apache.zookeeper.server.quorum.QuorumPeer.run(
> > > > QuorumPeer.java:727)
> > > > > > "WorkerReceiver[myid=210]" #25 daemon prio=5 os_prio=0
> > > > > > tid=0x00007efc6c2fc800 nid=0x1a3de waiting on condition
> > > > [0x00007efbbbcfd000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c016fbf0> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.ArrayBlockingQueue.poll(
> > > > ArrayBlockingQueue.java:418)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager.pollRecvQueue(
> > > > QuorumCnxManager.java:883)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.FastLeaderElection$
> > > > Messenger$WorkerReceiver.run(FastLeaderElection.java:205)
> > > > > > at java.lang.Thread.run(Thread.java:745)
> > > > > > "WorkerSender[myid=210]" #24 daemon prio=5 os_prio=0
> > > > > > tid=0x00007efc6c2f9000 nid=0x1a3dd waiting on condition
> > > > [0x00007efbbbdfe000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (parking)
> > > > > > at sun.misc.Unsafe.park(Native Method)
> > > > > > - parking to wait for  <0x00000005c016fec0> (a
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > ConditionObject)
> > > > > > at java.util.concurrent.locks.LockSupport.parkNanos(
> > > > LockSupport.java:215)
> > > > > > at
> > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$
> > > > ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> > > > > > at
> > > > > > java.util.concurrent.LinkedBlockingQueue.poll(
> > > > LinkedBlockingQueue.java:467)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.FastLeaderElection$
> > > > Messenger$WorkerSender.run(FastLeaderElection.java:362)
> > > > > > at java.lang.Thread.run(Thread.java:745)
> > > > > > "192.168.72.250:3888" #23 prio=5 os_prio=0 tid=0x00007efc6c2c2800
> > > > > > nid=0x1a3dc runnable [0x00007efc001d3000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.PlainSocketImpl.socketAccept(Native Method)
> > > > > > at
> > > > > > java.net.AbstractPlainSocketImpl.accept(
> > AbstractPlainSocketImpl.java:
> > > > 409)
> > > > > > at java.net.ServerSocket.implAccept(ServerSocket.java:545)
> > > > > > at java.net.ServerSocket.accept(ServerSocket.java:513)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumCnxManager$
> > > > Listener.run(QuorumCnxManager.java:491)
> > > > > > "NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181" #21 daemon prio=5
> > > > os_prio=0
> > > > > > tid=0x00007efc6c305000 nid=0x1a3db runnable [0x00007efc002d4000]
> > > > > >    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:93)
> > > > > > at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
> > > > > > - locked <0x00000005c0008620> (a sun.nio.ch.Util$2)
> > > > > > - locked <0x00000005c0008610> (a java.util.Collections$
> > > > UnmodifiableSet)
> > > > > > - locked <0x00000005c00084d8> (a sun.nio.ch.EPollSelectorImpl)
> > > > > > at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
> > > > > > at
> > > > > > org.apache.zookeeper.server.NIOServerCnxnFactory.run(
> > > > NIOServerCnxnFactory.java:178)
> > > > > > at java.lang.Thread.run(Thread.java:745)
> > > > > > "PurgeTask" #20 daemon prio=5 os_prio=0 tid=0x00007efc6c2a1800
> > > > nid=0x1a39a
> > > > > > in Object.wait() [0x00007efc003d5000]
> > > > > >    java.lang.Thread.State: TIMED_WAITING (on object monitor)
> > > > > > at java.lang.Object.wait(Native Method)
> > > > > > at java.util.TimerThread.mainLoop(Timer.java:552)
> > > > > > - locked <0x00000005c0002f30> (a java.util.TaskQueue)
> > > > > > at java.util.TimerThread.run(Timer.java:505)
> > > > > > "RMI TCP Accept-0" #19 daemon prio=5 os_prio=0
> > tid=0x00007efc6c23d800
> > > > > > nid=0x1a398 runnable [0x00007efc009f7000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > at java.net.PlainSocketImpl.socketAccept(Native Method)
> > > > > > at
> > > > > > java.net.AbstractPlainSocketImpl.accept(
> > AbstractPlainSocketImpl.java:
> > > > 409)
> > > > > > at java.net.ServerSocket.implAccept(ServerSocket.java:545)
> > > > > > at java.net.ServerSocket.accept(ServerSocket.java:513)
> > > > > > at
> > > > > > sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(
> > > > TCPTransport.java:400)
> > > > > > at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(
> > > > TCPTransport.java:372)
> > > > > > at java.lang.Thread.run(Thread.java:745)
> > > > > > "Service Thread" #17 daemon prio=9 os_prio=0 tid=0x00007efc6c106800
> > > > > > nid=0x1a397 runnable [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C1 CompilerThread11" #16 daemon prio=9 os_prio=0
> > > > tid=0x00007efc6c0fc000
> > > > > > nid=0x1a396 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C1 CompilerThread10" #15 daemon prio=9 os_prio=0
> > > > tid=0x00007efc6c0fa000
> > > > > > nid=0x1a395 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C1 CompilerThread9" #14 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0f8000
> > > > > > nid=0x1a394 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C1 CompilerThread8" #13 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0f5800
> > > > > > nid=0x1a393 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread7" #12 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0f3800
> > > > > > nid=0x1a392 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread6" #11 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0f1800
> > > > > > nid=0x1a391 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread5" #10 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0ef800
> > > > > > nid=0x1a390 waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread4" #9 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0e5800
> > > > > > nid=0x1a38f waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread3" #8 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0e3000
> > > > > > nid=0x1a38e waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread2" #7 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0e1000
> > > > > > nid=0x1a38d waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread1" #6 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0df000
> > > > > > nid=0x1a38c waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "C2 CompilerThread0" #5 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0d1800
> > > > > > nid=0x1a38b waiting on condition [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "Signal Dispatcher" #4 daemon prio=9 os_prio=0
> > tid=0x00007efc6c0cf800
> > > > > > nid=0x1a38a runnable [0x0000000000000000]
> > > > > >    java.lang.Thread.State: RUNNABLE
> > > > > > "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007efc6c0a5800
> > > > nid=0x1a389
> > > > > > in Object.wait() [0x00007efc28c06000]
> > > > > >    java.lang.Thread.State: WAITING (on object monitor)
> > > > > > at java.lang.Object.wait(Native Method)
> > > > > > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
> > > > > > - locked <0x00000005c01402e0> (a java.lang.ref.ReferenceQueue$
> > Lock)
> > > > > > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
> > > > > > at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
> > > > > > "Reference Handler" #2 daemon prio=10 os_prio=0
> > tid=0x00007efc6c0a1000
> > > > > > nid=0x1a388 in Object.wait() [0x00007efc28d07000]
> > > > > >    java.lang.Thread.State: WAITING (on object monitor)
> > > > > > at java.lang.Object.wait(Native Method)
> > > > > > at java.lang.Object.wait(Object.java:502)
> > > > > > at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
> > > > > > - locked <0x00000005c0007c38> (a java.lang.ref.Reference$Lock)
> > > > > > at java.lang.ref.Reference$ReferenceHandler.run(
> > Reference.java:153)
> > > > > > "main" #1 prio=5 os_prio=0 tid=0x00007efc6c008800 nid=0x1a379
in
> > > > > > Object.wait() [0x00007efc75e17000]
> > > > > >    java.lang.Thread.State: WAITING (on object monitor)
> > > > > > at java.lang.Object.wait(Native Method)
> > > > > > - waiting on <0x00000005c0007d28> (a
> > > > > > org.apache.zookeeper.server.quorum.QuorumPeer)
> > > > > > at java.lang.Thread.join(Thread.java:1245)
> > > > > > - locked <0x00000005c0007d28> (a
> > > > > > org.apache.zookeeper.server.quorum.QuorumPeer)
> > > > > > at java.lang.Thread.join(Thread.java:1319)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumPeerMain.
> > > > runFromConfig(QuorumPeerMain.java:152)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumPeerMain.
> > initializeAndRun(
> > > > QuorumPeerMain.java:111)
> > > > > > at
> > > > > > org.apache.zookeeper.server.quorum.QuorumPeerMain.main(
> > > > QuorumPeerMain.java:78)
> > > > > > "VM Thread" os_prio=0 tid=0x00007efc6c097800 nid=0x1a387 runnable
> > > > > > "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007efc6c01e000
> > > > > > nid=0x1a37a runnable
> > > > > > "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007efc6c01f800
> > > > > > nid=0x1a37b runnable
> > > > > > "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007efc6c021800
> > > > > > nid=0x1a37c runnable
> > > > > > "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007efc6c023000
> > > > > > nid=0x1a37d runnable
> > > > > > "GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007efc6c025000
> > > > > > nid=0x1a37e runnable
> > > > > > "GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007efc6c027000
> > > > > > nid=0x1a37f runnable
> > > > > > "GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007efc6c028800
> > > > > > nid=0x1a380 runnable
> > > > > > "GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007efc6c02a800
> > > > > > nid=0x1a381 runnable
> > > > > > "GC task thread#8 (ParallelGC)" os_prio=0 tid=0x00007efc6c02c800
> > > > > > nid=0x1a382 runnable
> > > > > > "GC task thread#9 (ParallelGC)" os_prio=0 tid=0x00007efc6c02e000
> > > > > > nid=0x1a383 runnable
> > > > > > "GC task thread#10 (ParallelGC)" os_prio=0 tid=0x00007efc6c030000
> > > > > > nid=0x1a384 runnable
> > > > > > "GC task thread#11 (ParallelGC)" os_prio=0 tid=0x00007efc6c031800
> > > > > > nid=0x1a385 runnable
> > > > > > "GC task thread#12 (ParallelGC)" os_prio=0 tid=0x00007efc6c033800
> > > > > > nid=0x1a386 runnable
> > > > > > "VM Periodic Task Thread" os_prio=0 tid=0x00007efc6c254800
> > nid=0x1a399
> > > > > > waiting on condition
> > > > > > JNI global references: 238
> > > > >
> > > > >
> > > > > ###
> > > > >
> > > > > On Thu, Oct 26, 2017 at 9:13 AM, Abraham Fine <afine@apache.org>
> > wrote:
> > > > >
> > > > > > Maybe it is a limitation of the mailing list infrastructure,
but
> > I'm
> > > > not
> > > > > > getting them.
> > > > > > Would it be possible to put the jstack output in a gist and
link
> > > > > > to it here?
> > > > > > Abe
> > > > > >
> > > > > >
> > > > > > On Thu, Oct 26, 2017, at 09:00, rammohan ganapavarapu wrote:
> > > > > > > Hmm, it is attached in my sent mail but any way i am attaching
> > > > again.>
> > > > > > > On Thu, Oct 26, 2017 at 8:58 AM, Abraham Fine
> > > > > > > <afine@apache.org> wrote:>> Hi Ram-
> > > > > > >>
> > > > > > >>  I don't see any jstack output attached to the email.
> > > > > > >>
> > > > > > >>  Thanks,
> > > > > > >>  Abe
> > > > > > >>
> > > > > > >>
> > > > > > >>
> > > > > > >> On Wed, Oct 25, 2017, at 18:17, rammohan ganapavarapu
wrote:
> > > > > > >>  > Abe,
> > > > > > >>  >
> > > > > > >>  > Under /node1 i have 30 child nodes but each child
node
> > doesn't
> > > > > > >>  > have>>  > any more nodes. I did took
jstack at the time of
> > > > latency,
> > > > > > please
> > > > > > >>  > find>>  > the attached. It is happening
with most of the
> > servers
> > > > i
> > > > > > didn't
> > > > > > >>  > check>>  > all of them.>
> > > > > > >>  > Thanks,
> > > > > > >>  > Ram
> > > > > > >>  >
> > > > > > >>  > On Wed, Oct 25, 2017 at 4:06 PM, Abraham Fine
> > > > > > >>  > <afine@apache.org> wrote:>> That's
strange. ZooKeeper's
> > reads
> > > > > > >>  > happen locally usually quickly.>>  >>
> > > > > > >>  >>  Can you tell us anything else about the
issue? Could you
> > > > > > >>  >>  possibly>>  >>  provide a jstack
output from a server that
> > is
> > > > slow
> > > > > > to respond?
> > > > > > >>  >>  Does>>  this happen with all of the
servers? Does it
> > matter if
> > > > > > >>  >>  the node>>  >>  you are>>
 reading from has many children?
> > > > > > >>  >>
> > > > > > >>  >>  Thanks,
> > > > > > >>  >>  Abe
> > > > > > >>  >>
> > > > > > >>  >>
> > > > > > >>  >> On Wed, Oct 25, 2017, at 09:18, rammohan
ganapavarapu wrote:
> > > > > > >>  >>  > Hi,
> > > > > > >>  >>  >
> > > > > > >>  >>  > We have a multi region zk cluster,
we are observing
> > latency
> > > > > > >>  >>  > for>>  >>  > just>>
 > local
> > > > > > >>  >>  > zk 'ls' command intermittently nothing
in logs dont know
> > how
> > > > > > >>  >>  > to>>  >>  > find>>
 >  reason for latency, any one have
> > any
> > > > > > thoughts?
> > > > > > >>  >>  >
> > > > > > >>  >>  > zkCli.sh ls /node1
> > > > > > >>  >>  >
> > > > > > >>  >>  > real 0m13.089s --When latency
> > > > > > >>  >>  > real 0m0.689s -- No latency
> > > > > > >>  >>  >
> > > > > > >>  >>  > Thanks,
> > > > > > >>  >>  > Ram
> > > > > > >>
> > > > > >
> > > > > >
> > > >
> >

Mime
View raw message