Possibility of non being able to accept new connections due to the lock on the kryonet Server

Description

and I were doing some tests together and we noticed that when large amount of data is sent from the agent to the CMR, it can occur that no new connections can be established after some time. We are not sure if this is result of the load or this was caused due to the closing of the agent.

We got the thread dump, it should be reproducible.

Full thread dump OpenJDK 64-Bit Server VM (24.80-b11 mixed mode): "Attach Listener" daemon prio=10 tid=0x00007efd88001000 nid=0x43fe waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "pool-5-thread-1" prio=10 tid=0x00007efd3c002000 nid=0x439f waiting on condition [0x00007efd984d7000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b94e5230> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "OkHttp ConnectionPool" daemon prio=10 tid=0x00007efd58008000 nid=0x4387 in Object.wait() [0x00007efd985d8000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b718ad88> (a com.squareup.okhttp.ConnectionPool) at java.lang.Object.wait(Object.java:461) at com.squareup.okhttp.ConnectionPool.performCleanup(ConnectionPool.java:305) - locked <0x00000000b718ad88> (a com.squareup.okhttp.ConnectionPool) at com.squareup.okhttp.ConnectionPool.runCleanupUntilPoolIsEmpty(ConnectionPool.java:242) at com.squareup.okhttp.ConnectionPool.access$000(ConnectionPool.java:54) at com.squareup.okhttp.ConnectionPool$1.run(ConnectionPool.java:97) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "agent-service-executor-service-thread-0" daemon prio=10 tid=0x00007efcf8004800 nid=0x4384 waiting on condition [0x00007efd986d9000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b91337e0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "kryo-net-object-space-executor-service-thread-2" daemon prio=10 tid=0x00007efd14cd6800 nid=0x437d waiting for monitor entry [0x00007efd987da000] java.lang.Thread.State: BLOCKED (on object monitor) at rocks.inspectit.shared.all.storage.nio.stream.AbstractExtendedByteBufferInputStream.close(AbstractExtendedByteBufferInputStream.java:243) - waiting to lock <0x00000000b8b32f28> (a rocks.inspectit.shared.all.storage.nio.stream.SocketExtendedByteBufferInputStream) at rocks.inspectit.shared.all.kryonet.TcpConnection.close(TcpConnection.java:355) at rocks.inspectit.shared.all.kryonet.Connection.close(Connection.java:177) at rocks.inspectit.shared.all.kryonet.Connection.sendTCP(Connection.java:114) at rocks.inspectit.shared.all.kryonet.rmi.ObjectSpace.invoke(ObjectSpace.java:295) at rocks.inspectit.shared.all.kryonet.rmi.ObjectSpace$1$1.run(ObjectSpace.java:100) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "kryo-net-object-space-executor-service-thread-1" daemon prio=10 tid=0x00007efd14c97800 nid=0x4375 waiting for monitor entry [0x00007efd988db000] java.lang.Thread.State: BLOCKED (on object monitor) at rocks.inspectit.shared.all.storage.nio.stream.AbstractExtendedByteBufferInputStream.close(AbstractExtendedByteBufferInputStream.java:243) - waiting to lock <0x00000000b8b32f28> (a rocks.inspectit.shared.all.storage.nio.stream.SocketExtendedByteBufferInputStream) at rocks.inspectit.shared.all.kryonet.TcpConnection.close(TcpConnection.java:355) at rocks.inspectit.shared.all.kryonet.Connection.close(Connection.java:177) at rocks.inspectit.shared.all.kryonet.Connection.sendTCP(Connection.java:114) at rocks.inspectit.shared.all.kryonet.rmi.ObjectSpace.invoke(ObjectSpace.java:295) at rocks.inspectit.shared.all.kryonet.rmi.ObjectSpace$1$1.run(ObjectSpace.java:100) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "socket-read-executor-service-thread-1" daemon prio=10 tid=0x00007efd14c96800 nid=0x4374 runnable [0x00007efd989dc000] java.lang.Thread.State: RUNNABLE at java.lang.Throwable.fillInStackTrace(Native Method) at java.lang.Throwable.fillInStackTrace(Throwable.java:783) - locked <0x00000000a21e40d8> (a java.nio.channels.ClosedChannelException) at java.lang.Throwable.<init>(Throwable.java:250) at java.lang.Exception.<init>(Exception.java:54) at java.io.IOException.<init>(IOException.java:47) at java.nio.channels.ClosedChannelException.<init>(ClosedChannelException.java:52) at sun.nio.ch.SocketChannelImpl.ensureReadOpen(SocketChannelImpl.java:257) - locked <0x00000000b95e2350> (a java.lang.Object) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:300) - locked <0x00000000b95e2320> (a java.lang.Object) at rocks.inspectit.shared.all.storage.nio.stream.SocketExtendedByteBufferInputStream$SocketReadRunnable.run(SocketExtendedByteBufferInputStream.java:132) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "kryo-net-object-space-executor-service-thread-0" daemon prio=10 tid=0x00007efd14cae800 nid=0x4373 waiting for monitor entry [0x00007efd98add000] java.lang.Thread.State: BLOCKED (on object monitor) at rocks.inspectit.shared.all.storage.nio.stream.AbstractExtendedByteBufferInputStream.close(AbstractExtendedByteBufferInputStream.java:243) - waiting to lock <0x00000000b8b32f28> (a rocks.inspectit.shared.all.storage.nio.stream.SocketExtendedByteBufferInputStream) at rocks.inspectit.shared.all.kryonet.TcpConnection.close(TcpConnection.java:355) at rocks.inspectit.shared.all.kryonet.Connection.close(Connection.java:177) at rocks.inspectit.shared.all.kryonet.Connection.sendTCP(Connection.java:114) at rocks.inspectit.shared.all.kryonet.rmi.ObjectSpace.invoke(ObjectSpace.java:295) at rocks.inspectit.shared.all.kryonet.rmi.ObjectSpace$1$1.run(ObjectSpace.java:100) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "socket-read-executor-service-thread-0" daemon prio=10 tid=0x00007efd14011800 nid=0x4372 waiting on condition [0x00007efd98bde000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b91274f0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "DestroyJavaVM" prio=10 tid=0x00007efdd800b800 nid=0x432c waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Server" prio=10 tid=0x00007efdd8fa4800 nid=0x435e waiting on condition [0x00007efd98cdf000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b96124a8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at rocks.inspectit.shared.all.storage.nio.stream.AbstractExtendedByteBufferInputStream.bufferChange(AbstractExtendedByteBufferInputStream.java:221) - locked <0x00000000b8b32f28> (a rocks.inspectit.shared.all.storage.nio.stream.SocketExtendedByteBufferInputStream) at rocks.inspectit.shared.all.storage.nio.stream.AbstractExtendedByteBufferInputStream.read(AbstractExtendedByteBufferInputStream.java:197) at com.esotericsoftware.kryo.io.Input.fill(Input.java:146) at com.esotericsoftware.kryo.io.Input.require(Input.java:178) at com.esotericsoftware.kryo.io.Input.readVarInt(Input.java:355) at com.esotericsoftware.kryo.util.DefaultClassResolver.readClass(DefaultClassResolver.java:109) at com.esotericsoftware.kryo.Kryo.readClass(Kryo.java:641) at com.esotericsoftware.kryo.Kryo.readClassAndObject(Kryo.java:752) at rocks.inspectit.shared.all.kryonet.ExtendedSerializationImpl.read(ExtendedSerializationImpl.java:156) at rocks.inspectit.shared.all.kryonet.TcpConnection.readObject(TcpConnection.java:209) at rocks.inspectit.shared.all.kryonet.Server.update(Server.java:233) - locked <0x00000000b9133828> (a sun.nio.ch.Util$2) at rocks.inspectit.shared.all.kryonet.Server.run(Server.java:408) at java.lang.Thread.run(Thread.java:745) "btpool0-4 - Acceptor0 SocketConnector@0.0.0.0:8182" prio=10 tid=0x00007efdd8ea2000 nid=0x435d runnable [0x00007efd98de0000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at org.mortbay.jetty.bio.SocketConnector.accept(SocketConnector.java:99) at org.mortbay.jetty.AbstractConnector$Acceptor.run(AbstractConnector.java:708) at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451) "btpool0-3" prio=10 tid=0x00007efdd8ea0000 nid=0x435c in Object.wait() [0x00007efd98ee1000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b864ef60> (a org.mortbay.thread.BoundedThreadPool$PoolThread) at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:491) - locked <0x00000000b864ef60> (a org.mortbay.thread.BoundedThreadPool$PoolThread) "btpool0-2" prio=10 tid=0x00007efdd8e9b000 nid=0x435b in Object.wait() [0x00007efd98fe2000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b864efd0> (a org.mortbay.thread.BoundedThreadPool$PoolThread) at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:491) - locked <0x00000000b864efd0> (a org.mortbay.thread.BoundedThreadPool$PoolThread) "btpool0-1" prio=10 tid=0x00007efdd8ea6000 nid=0x435a in Object.wait() [0x00007efd990e3000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b864f040> (a org.mortbay.thread.BoundedThreadPool$PoolThread) at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:491) - locked <0x00000000b864f040> (a org.mortbay.thread.BoundedThreadPool$PoolThread) "btpool0-0" prio=10 tid=0x00007efdd8e9d000 nid=0x4359 in Object.wait() [0x00007efd991e4000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b5c6c740> (a org.mortbay.thread.BoundedThreadPool$PoolThread) at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:491) - locked <0x00000000b5c6c740> (a org.mortbay.thread.BoundedThreadPool$PoolThread) "agent-storage-service-process-data-thread-1" daemon prio=10 tid=0x00007efdd8e84000 nid=0x4357 waiting on condition [0x00007efd992e5000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b9575e80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:374) at rocks.inspectit.server.service.AgentStorageService$ProcessDataThread.run(AgentStorageService.java:207) "agent-storage-service-process-data-thread-0" daemon prio=10 tid=0x00007efdd8e50800 nid=0x4356 waiting on condition [0x00007efd993e6000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b9575e80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:374) at rocks.inspectit.server.service.AgentStorageService$ProcessDataThread.run(AgentStorageService.java:207) "timer-data-aggregator-cache-cleaner-thread" daemon prio=10 tid=0x00007efdd99b0800 nid=0x4355 waiting on condition [0x00007efd994e7000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at rocks.inspectit.server.dao.impl.TimerDataAggregatorCacheCleaner.run(TimerDataAggregatorCacheCleaner.java:57) "scheduled-executor-service-thread-4" daemon prio=10 tid=0x00007efdd99aa800 nid=0x4354 waiting on condition [0x00007efd995e8000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b44ce288> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "buffer-indexing-thread" daemon prio=10 tid=0x00007efdd8651000 nid=0x4353 waiting on condition [0x00007efd996e9000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b7f6abd8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at rocks.inspectit.server.cache.impl.AbstractBufferElementProcessor.process(AbstractBufferElementProcessor.java:84) at rocks.inspectit.server.cache.impl.IndexBufferElementProcessor.process(IndexBufferElementProcessor.java:49) at rocks.inspectit.server.cache.impl.AtomicBuffer.indexNext(AtomicBuffer.java:380) at rocks.inspectit.server.cache.impl.BufferIndexer.work(BufferIndexer.java:36) at rocks.inspectit.server.cache.impl.BufferWorker.run(BufferWorker.java:63) "buffer-evicting-thread" daemon prio=10 tid=0x00007efdd8650000 nid=0x4352 waiting on condition [0x00007efd997ea000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b68b3710> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at rocks.inspectit.server.cache.impl.AtomicBuffer.evict(AtomicBuffer.java:296) at rocks.inspectit.server.cache.impl.BufferEvictor.work(BufferEvictor.java:35) at rocks.inspectit.server.cache.impl.BufferWorker.run(BufferWorker.java:63) "buffer-analyzing-thread" daemon prio=10 tid=0x00007efdd8655800 nid=0x4351 waiting on condition [0x00007efd998eb000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b7f73f18> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at rocks.inspectit.server.cache.impl.AbstractBufferElementProcessor.process(AbstractBufferElementProcessor.java:84) at rocks.inspectit.server.cache.impl.AtomicBuffer.analyzeNext(AtomicBuffer.java:368) at rocks.inspectit.server.cache.impl.BufferAnalyzer.work(BufferAnalyzer.java:35) at rocks.inspectit.server.cache.impl.BufferWorker.run(BufferWorker.java:63) "Thread-6" prio=10 tid=0x00007efdd865c800 nid=0x4350 runnable [0x00007efd999ec000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at rocks.inspectit.server.anomaly.stream.simulator.StreamSimulationInterface.run(StreamSimulationInterface.java:72) at java.lang.Thread.run(Thread.java:745) "pool-4-thread-1" prio=10 tid=0x00007efdd8639800 nid=0x434f waiting on condition [0x00007efd99aed000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b89e0e38> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at com.lmax.disruptor.BlockingWaitStrategy.waitFor(BlockingWaitStrategy.java:45) at com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:56) at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:124) at java.lang.Thread.run(Thread.java:745) "scheduled-executor-service-thread-3" daemon prio=10 tid=0x00007efdd8659800 nid=0x434e waiting on condition [0x00007efd99bee000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b44ce288> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1085) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "scheduled-executor-service-thread-2" daemon prio=10 tid=0x00007efdd8633000 nid=0x434d waiting on condition [0x00007efd99cef000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b44ce288> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1085) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "scheduled-executor-service-thread-1" daemon prio=10 tid=0x00007efdd8636000 nid=0x434c waiting on condition [0x00007efd99df0000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b44ce288> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1085) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "scheduled-executor-service-thread-0" daemon prio=10 tid=0x00007efdd8627800 nid=0x434b waiting on condition [0x00007efd99ef1000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b44ce288> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1085) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "pool-3-thread-1" prio=10 tid=0x00007efdd9171000 nid=0x434a waiting on condition [0x00007efd9a475000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b7f73f30> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "pool-2-thread-1" prio=10 tid=0x00007efdd9142000 nid=0x4349 waiting on condition [0x00007efd9a576000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000b7f65448> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "H2 Log Writer INSPECTIT" daemon prio=10 tid=0x00007efd740fd800 nid=0x4348 in Object.wait() [0x00007efd9a99d000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b66d5828> (a org.h2.store.WriterThread) at org.h2.store.WriterThread.run(WriterThread.java:103) - locked <0x00000000b66d5828> (a org.h2.store.WriterThread) at java.lang.Thread.run(Thread.java:745) "H2 File Lock Watchdog /home/ise/Desktop/CMR Test/CMR/db/inspectit.lock.db" daemon prio=10 tid=0x00007efd7401b000 nid=0x4347 waiting on condition [0x00007efd9aa9e000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.h2.store.FileLock.run(FileLock.java:517) at java.lang.Thread.run(Thread.java:745) "C3P0PooledConnectionPoolManager[identityToken->z8kfsx9j2lk79m6pfmj5|33c1da84]-HelperThread-#2" daemon prio=10 tid=0x00007efdd9a0a000 nid=0x4345 in Object.wait() [0x00007efd9a677000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b4231978> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner) at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683) - locked <0x00000000b4231978> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner) "C3P0PooledConnectionPoolManager[identityToken->z8kfsx9j2lk79m6pfmj5|33c1da84]-HelperThread-#1" daemon prio=10 tid=0x00007efdd9a08800 nid=0x4344 in Object.wait() [0x00007efd9a778000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b4231978> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner) at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683) - locked <0x00000000b4231978> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner) "C3P0PooledConnectionPoolManager[identityToken->z8kfsx9j2lk79m6pfmj5|33c1da84]-HelperThread-#0" daemon prio=10 tid=0x00007efdd9a04000 nid=0x4343 in Object.wait() [0x00007efd9a879000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b4231978> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner) at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:683) - locked <0x00000000b4231978> (a com.mchange.v2.async.ThreadPoolAsynchronousRunner) "C3P0PooledConnectionPoolManager[identityToken->z8kfsx9j2lk79m6pfmj5|33c1da84]-AdminTaskTimer" daemon prio=10 tid=0x00007efdd9a01000 nid=0x4342 in Object.wait() [0x00007efd9ada7000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b422fba8> (a java.util.TaskQueue) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x00000000b422fba8> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) "Service Thread" daemon prio=10 tid=0x00007efdd81a6800 nid=0x433f runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=10 tid=0x00007efdd81a4000 nid=0x433e waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=10 tid=0x00007efdd81a1800 nid=0x433d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=10 tid=0x00007efdd819f800 nid=0x433c runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Surrogate Locker Thread (Concurrent GC)" daemon prio=10 tid=0x00007efdd819d800 nid=0x433b waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=10 tid=0x00007efdd8173800 nid=0x433a in Object.wait() [0x00007efdb422f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b447fe68> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000000b447fe68> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209) "Reference Handler" daemon prio=10 tid=0x00007efdd8171800 nid=0x4339 in Object.wait() [0x00007efdb4330000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000b4098b58> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x00000000b4098b58> (a java.lang.ref.Reference$Lock) "VM Thread" prio=10 tid=0x00007efdd816d800 nid=0x4338 runnable "Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x00007efdd801d000 nid=0x432d runnable "Gang worker#1 (Parallel GC Threads)" prio=10 tid=0x00007efdd801e800 nid=0x432e runnable "Gang worker#2 (Parallel GC Threads)" prio=10 tid=0x00007efdd8020800 nid=0x432f runnable "Gang worker#3 (Parallel GC Threads)" prio=10 tid=0x00007efdd8022000 nid=0x4330 runnable "Gang worker#4 (Parallel GC Threads)" prio=10 tid=0x00007efdd8024000 nid=0x4331 runnable "Gang worker#5 (Parallel GC Threads)" prio=10 tid=0x00007efdd8026000 nid=0x4332 runnable "Gang worker#6 (Parallel GC Threads)" prio=10 tid=0x00007efdd8027800 nid=0x4333 runnable "Gang worker#7 (Parallel GC Threads)" prio=10 tid=0x00007efdd8029800 nid=0x4334 runnable "Concurrent Mark-Sweep GC Thread" prio=10 tid=0x00007efdd8102800 nid=0x4337 waiting on condition "Gang worker#0 (Parallel CMS Threads)" prio=10 tid=0x00007efdd80fe800 nid=0x4335 runnable "Gang worker#1 (Parallel CMS Threads)" prio=10 tid=0x00007efdd8100800 nid=0x4336 runnable "VM Periodic Task Thread" prio=10 tid=0x00007efdd81aa000 nid=0x4340 waiting on condition JNI global references: 290

Environment

None

Gliffy Diagrams

Activity

Technical User 
October 14, 2016 at 12:27 PM

SUCCESS: Integrated in

inspectIT - Integration #203
INSPECTIT-2202: Improving agent-server communication (react on socket (patrice.bouillet: 7201df17efe5e7863e10d4074acdd4286e1fb69b)

  • (edit) inspectit.shared.all/src/main/java/rocks/inspectit/shared/all/storage/nio/ByteBufferProvider.java

  • (edit) inspectit.shared.cs/src/main/java/rocks/inspectit/shared/cs/storage/nio/stream/ExtendedByteBufferInputStream.java

  • (edit) inspectit.agent.java/src/main/java/rocks/inspectit/agent/java/analyzer/impl/InstrumentationAppliedRunnable.java

  • (edit) inspectit.shared.all/src/main/java/rocks/inspectit/shared/all/storage/nio/stream/SocketExtendedByteBufferInputStream.java

  • (edit) inspectit.agent.java/src/test/java/rocks/inspectit/agent/java/connection/impl/KryoNetConnectionTest.java

  • (edit) inspectit.shared.all/src/test/java/rocks/inspectit/shared/all/storage/nio/stream/SocketExtendedByteBufferInputStreamTest.java

  • (edit) inspectit.shared.all/src/main/java/rocks/inspectit/shared/all/storage/nio/stream/AbstractExtendedByteBufferInputStream.java

  • (edit) inspectit.agent.java/src/main/java/rocks/inspectit/agent/java/analyzer/impl/AnalyzeCallable.java

  • (edit) inspectit.agent.java/src/main/java/rocks/inspectit/agent/java/connection/impl/KryoNetConnection.java

  • (edit) inspectit.server/src/main/external-resources/config/default.xml

Ivan Senic 
October 4, 2016 at 1:41 PM

OK after a lot of testing I figured out that yes there is a problem and possibility to dead-lock on the dropped socket connection, but the communication itself is not a bottleneck for sure. I plugged out all the processing on the CMR and receiving of large amount of data send by the agent is possible (I can not even simulate the enough load to brake it).

The bottle neck starts to be the buffer with the combination with high garbage collection, especially in the use case that we have here with lot of empty invocations, all invoked on the same method. Simply for each on of those we need to create new buffer element and to index it individually, thus there we end up in really big maps and high need for GC.

Anyhow everything I said on Friday you can forget. I will tough submit fix to improve the reaction on dropped socket and general functioning with the high amount of connections as we saw that it can occur that we end up with no byte buffer available due to the small pool.

Ivan Senic 
September 14, 2016 at 12:37 PM

I opened the ticket here that could actually solve all of our problems https://github.com/EsotericSoftware/kryonet/issues/121. If this goes into the Kryonet, then I this we can easily remove the existing Kryonet code from our repository and directly use only the dependency. Would be a win win situation for us.

Ivan Senic 
September 13, 2016 at 5:21 PM

I tried to solve this today and I was correct the problem was mainly in not reacting to the socket channel denoting that the stream has reach the eof.

However, during this analysis I figured out that I did a complete stupidity, and that the whole reading of the data from the socket must be rewritten. The problem here is that the socket channel is non blocking, but I am actually blocking it on the reading. What I am doing is waiting for all bytes of the next sent object to the read from the socket channel. Instead of that I should return as soon as I recognize that I am missing some bytes (not on the socket yet) as this is the way this should be handled imo. Now this is not easy actually, in original Kryonet implementation they do it correct, but they have a limit in how big the sent object can be. That's because they try to put all the needed bytes for one object in one byte buffer. We overcame this and allowed unlimited size of the object, but on the other hand we are blocking the update thread when reading (which is basically very problematic as other connections can not be served until this one socket channel fully sent the object. I need to fix this, as I assume this is the reason and I saw a big drop in data being transferred when more than one agent is connected. However, this is not simple and at the moment I don't have a clear idea how to do it.

Ivan Senic 
September 8, 2016 at 1:05 PM

app ~ 50,000+ invocations/requests per second.. each invocation has no children..

Fixed

Details

Assignee

Reporter

Integrator

Sprint

Fix versions

Affects versions

Priority

Created September 8, 2016 at 11:35 AM
Updated October 14, 2016 at 12:30 PM
Resolved October 14, 2016 at 12:30 PM