Re: local call latency
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 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" 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=0x7efbfc001000 > > > > > > nid=0x10cfb waiting on condition [0x] > > > > > >java.lang.Thread.State: RUNNABLE > > > > > > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x7efba0036000 > > > > nid=0x1a951 > > > > > > waiting on condition [0x7efbbaeef000] > > > > > >java.lang.Thread.State: WAITING (parking) > > > > > > at sun.misc.Unsafe.park(Native Method) > > > > > > - parking to wait for <0x0006c55eced0> (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=0x7efba0035800 > > > > > > nid=0x1a950 waiting on condition [0x7efbbaff] > > > > > >java.lang.Thread.State: WAITING (parking) > > > > > > at sun.misc.Unsafe.park(Native Method) > > > > > > - parking to wait for <0x0006c55ec2e8> (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=0x7efba004d800 > > > > > > nid=0x1a94f in Object.wait() [0x7efbbb0f1000] > > > > > >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 <0x0006c55eb8e0> (a > > > > > > org.apache.zookeeper.server.quorum.CommitProcessor) > > > > > > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x7efba8013000 > > > > > > nid=0x1a415 runnable [0x7efbbb1f2000] > > > > > >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)
Re: local call latency
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 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" 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=0x7efbfc001000 > > > > > nid=0x10cfb waiting on condition [0x] > > > > >java.lang.Thread.State: RUNNABLE > > > > > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x7efba0036000 > > > nid=0x1a951 > > > > > waiting on condition [0x7efbbaeef000] > > > > >java.lang.Thread.State: WAITING (parking) > > > > > at sun.misc.Unsafe.park(Native Method) > > > > > - parking to wait for <0x0006c55eced0> (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=0x7efba0035800 > > > > > nid=0x1a950 waiting on condition [0x7efbbaff] > > > > >java.lang.Thread.State: WAITING (parking) > > > > > at sun.misc.Unsafe.park(Native Method) > > > > > - parking to wait for <0x0006c55ec2e8> (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=0x7efba004d800 > > > > > nid=0x1a94f in Object.wait() [0x7efbbb0f1000] > > > > >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 <0x0006c55eb8e0> (a > > > > > org.apache.zookeeper.server.quorum.CommitProcessor) > > > > > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x7efba8013000 > > > > > nid=0x1a415 runnable [0x7efbbb1f2000] > > > > >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=0x7efba8011000 > > > > > nid=0x1a414 waiting on condition [0x7efbbb2f3000] > > > > >java.lang.Thread.State: TIMED_WAITING (parking) > > > > > at sun.misc.Unsafe.park(Native Method) > > > > > - parking to wait for <0x0005c018c938> (a > > > > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ > ConditionObject) > > > > > at java.util.concurrent.locks.LockSupport.parkNanos( > > > LockSupport.java:215) > > > > > at > > > > > java.util.concurren
Re: local call latency
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" 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=0x7efbfc001000 > > > > nid=0x10cfb waiting on condition [0x] > > > >java.lang.Thread.State: RUNNABLE > > > > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x7efba0036000 > > nid=0x1a951 > > > > waiting on condition [0x7efbbaeef000] > > > >java.lang.Thread.State: WAITING (parking) > > > > at sun.misc.Unsafe.park(Native Method) > > > > - parking to wait for <0x0006c55eced0> (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=0x7efba0035800 > > > > nid=0x1a950 waiting on condition [0x7efbbaff] > > > >java.lang.Thread.State: WAITING (parking) > > > > at sun.misc.Unsafe.park(Native Method) > > > > - parking to wait for <0x0006c55ec2e8> (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=0x7efba004d800 > > > > nid=0x1a94f in Object.wait() [0x7efbbb0f1000] > > > >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 <0x0006c55eb8e0> (a > > > > org.apache.zookeeper.server.quorum.CommitProcessor) > > > > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x7efba8013000 > > > > nid=0x1a415 runnable [0x7efbbb1f2000] > > > >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=0x7efba8011000 > > > > nid=0x1a414 waiting on condition [0x7efbbb2f3000] > > > >java.lang.Thread.State: TIMED_WAITING (parking) > > > > at sun.misc.Unsafe.park(Native Method) > > > > - parking to wait for <0x0005c018c938> (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.QuorumCnxMana
Re: local call latency
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" 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=0x7efbfc001000 > > > nid=0x10cfb waiting on condition [0x] > > >java.lang.Thread.State: RUNNABLE > > > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x7efba0036000 > nid=0x1a951 > > > waiting on condition [0x7efbbaeef000] > > >java.lang.Thread.State: WAITING (parking) > > > at sun.misc.Unsafe.park(Native Method) > > > - parking to wait for <0x0006c55eced0> (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=0x7efba0035800 > > > nid=0x1a950 waiting on condition [0x7efbbaff] > > >java.lang.Thread.State: WAITING (parking) > > > at sun.misc.Unsafe.park(Native Method) > > > - parking to wait for <0x0006c55ec2e8> (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=0x7efba004d800 > > > nid=0x1a94f in Object.wait() [0x7efbbb0f1000] > > >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 <0x0006c55eb8e0> (a > > > org.apache.zookeeper.server.quorum.CommitProcessor) > > > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x7efba8013000 > > > nid=0x1a415 runnable [0x7efbbb1f2000] > > >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=0x7efba8011000 > > > nid=0x1a414 waiting on condition [0x7efbbb2f3000] > > >java.lang.Thread.State: TIMED_WAITING (parking) > > > at sun.misc.Unsafe.park(Native Method) > > > - parking to wait for <0x0005c018c938> (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=0x7efba800f800 > > > nid=0x1a413 runnable [0x7efbbb3f4000] > > >java.lang.Thread.State: RUNNABLE > > > at java.net.SocketInputStrea
Re: local call latency
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=0x7efbfc001000 > > nid=0x10cfb waiting on condition [0x] > >java.lang.Thread.State: RUNNABLE > > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x7efba0036000 nid=0x1a951 > > waiting on condition [0x7efbbaeef000] > >java.lang.Thread.State: WAITING (parking) > > at sun.misc.Unsafe.park(Native Method) > > - parking to wait for <0x0006c55eced0> (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=0x7efba0035800 > > nid=0x1a950 waiting on condition [0x7efbbaff] > >java.lang.Thread.State: WAITING (parking) > > at sun.misc.Unsafe.park(Native Method) > > - parking to wait for <0x0006c55ec2e8> (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=0x7efba004d800 > > nid=0x1a94f in Object.wait() [0x7efbbb0f1000] > >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 <0x0006c55eb8e0> (a > > org.apache.zookeeper.server.quorum.CommitProcessor) > > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x7efba8013000 > > nid=0x1a415 runnable [0x7efbbb1f2000] > >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=0x7efba8011000 > > nid=0x1a414 waiting on condition [0x7efbbb2f3000] > >java.lang.Thread.State: TIMED_WAITING (parking) > > at sun.misc.Unsafe.park(Native Method) > > - parking to wait for <0x0005c018c938> (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=0x7efba800f800 > > nid=0x1a413 runnable [0x7efbbb3f4000] > >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.se
Re: local call latency
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=0x7efbfc001000 > nid=0x10cfb waiting on condition [0x] >java.lang.Thread.State: RUNNABLE > "SyncThread:210" #74 prio=5 os_prio=0 tid=0x7efba0036000 nid=0x1a951 > waiting on condition [0x7efbbaeef000] >java.lang.Thread.State: WAITING (parking) > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <0x0006c55eced0> (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=0x7efba0035800 > nid=0x1a950 waiting on condition [0x7efbbaff] >java.lang.Thread.State: WAITING (parking) > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <0x0006c55ec2e8> (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=0x7efba004d800 > nid=0x1a94f in Object.wait() [0x7efbbb0f1000] >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 <0x0006c55eb8e0> (a > org.apache.zookeeper.server.quorum.CommitProcessor) > "RecvWorker:204" #40 daemon prio=5 os_prio=0 tid=0x7efba8013000 > nid=0x1a415 runnable [0x7efbbb1f2000] >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=0x7efba8011000 > nid=0x1a414 waiting on condition [0x7efbbb2f3000] >java.lang.Thread.State: TIMED_WAITING (parking) > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <0x0005c018c938> (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=0x7efba800f800 > nid=0x1a413 runnable [0x7efbbb3f4000] >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=0x7efba800d800 > nid=0x1a412 waiting on condition [0x7efbbb4f5000] >java.lang.Thread.State: TIMED_WAITING (parking) > at sun.misc.Unsafe.park(Native Method) > - parking to wait for <0x0005c018bf00> (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.
Re: local call latency
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 > 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 >> > 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
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 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 > > 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
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 > 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
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 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
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
