You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@zookeeper.apache.org by rammohan ganapavarapu <ra...@gmail.com> on 2017/10/25 16:18:20 UTC

local call latency

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

Re: local call latency

Posted by Abraham Fine <af...@apache.org>.
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 <af...@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" <af...@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 <af...@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
> > > > > > > <af...@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
> > > > > > >>  > <af...@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
> > > > > > >>
> > > > > >
> > > > > >
> > > >
> >

Re: local call latency

Posted by rammohan ganapavarapu <ra...@gmail.com>.
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 <af...@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" <af...@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 <af...@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
> > > > > > <af...@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
> > > > > >>  > <af...@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
> > > > > >>
> > > > >
> > > > >
> > >
>

Re: local call latency

Posted by Abraham Fine <af...@apache.org>.
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" <af...@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 <af...@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
> > > > > <af...@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
> > > > >>  > <af...@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
> > > > >>
> > > >
> > > >
> >

Re: local call latency

Posted by rammohan ganapavarapu <ra...@gmail.com>.
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" <af...@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 <af...@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
> > > > <af...@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
> > > >>  > <af...@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
> > > >>
> > >
> > >
>

Re: local call latency

Posted by Abraham Fine <af...@apache.org>.
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 <af...@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
> > > <af...@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
> > >>  > <af...@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
> > >>
> >
> >

Re: local call latency

Posted by rammohan ganapavarapu <ra...@gmail.com>.
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 <af...@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
> > <af...@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
> >>  > <af...@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
> >>
>
>

Re: local call latency

Posted by Abraham Fine <af...@apache.org>.
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
> <af...@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
>>  > <af...@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
>> 


Re: local call latency

Posted by rammohan ganapavarapu <ra...@gmail.com>.
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 <af...@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
> > <af...@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
>
>

Re: local call latency

Posted by Abraham Fine <af...@apache.org>.
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
> <af...@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


Re: local call latency

Posted by rammohan ganapavarapu <ra...@gmail.com>.
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 <af...@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
>

Re: local call latency

Posted by Abraham Fine <af...@apache.org>.
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