Thread#sleep eats CPU while sampling

Questions about YourKit Java Profiler
Post Reply
krasa
Posts: 2
Joined: Wed May 20, 2015 10:33 am

Thread#sleep eats CPU while sampling

Post by krasa »

Hello,

I have an application using Netty, when I enable Sampling, it starts to eat a lot of CPU, and YourKit shows that it is in Thread#sleep.
Image

Is it normal? Tracing does not have this problem.

I had also similar problem which I "solved" by not using yourkit agent... please see https://github.com/netty/netty/issues/3 ... t-92302843
Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Thread#sleep eats CPU while sampling

Post by Anton Katilin »

Hi,

Sleep does not eat CPU. Please note it has "[Wall time]" label. Although this method does not actually consume much CPU, we anyway show it in the estimation view with its wall (elapsed) time. This is done to avoid confusion of some users who did not find sleep() in the results, did not realize the actual reason and claimed it was missing.

Instead, the CPU usage increase that you observe is likely the overhead of sampling itself. Yes, sampling is a low overhead method in a general case, but there are corner cases when any method may expose a significant overhead.

According to the screenshot, you've got 556 threads running in parallel. It's a lot. During sampling JVM is asked to provide current stack trace for each of them. Getting the stack trace is relatively light weight operation, but as the number of threads grows its time grows too. It also matters how deep the stacks are.

Please also note that the kernel time (red line) has significantly increased too. This means that much CPU work is performed in system calls. I would attribute this to JVM's activity for getting the stacks.

As an experiment, you may increase the sampling period in the sampling settings from the default 20 ms to e.g. 100 ms, then start sampling, to see how this affects the CPU usage:
https://www.yourkit.com/docs/java/help/ ... ttings.jsp

Best regards,
Anton
krasa
Posts: 2
Joined: Wed May 20, 2015 10:33 am

Re: Thread#sleep eats CPU while sampling

Post by krasa »

Thank you, increased sampling period helped, now I see only periodic peeks.


I wanted to see what it does with 3000 threads, and stack telemetry itself can eat the whole cpu core - and i see no settings of period for that - but even bigger problem is that EDT is blocked for a very long time in the YourKit application when I want to see the telemetry.
(but this is only edge case, I do not have so many threads, so I do not expect you to do anything with it...)

Code: Select all

2015-05-21 10:40:17
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.45-b02 mixed mode):

"RMI TCP Connection(2)-10.254.0.47" #43 daemon prio=5 os_prio=0 tid=0x0000000020b52800 nid=0x8898 runnable [0x00000000256bd000]
   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 <0x00000007774a8d90> (a java.io.BufferedInputStream)
	at java.io.FilterInputStream.read(FilterInputStream.java:83)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:550)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$254(TCPTransport.java:683)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$28/1462392811.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x00000007774a8ed0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"JMX server connection timeout 42" #42 daemon prio=5 os_prio=0 tid=0x0000000020b51800 nid=0x36a0 in Object.wait() [0x00000000252df000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:168)
	- locked <0x0000000777485d88> (a [I)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"RMI TCP Connection(idle)" #41 daemon prio=5 os_prio=0 tid=0x0000000020b51000 nid=0x7874 waiting on condition [0x0000000022cfe000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c03548a0> (a java.util.concurrent.SynchronousQueue$TransferStack)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"RMI TCP Accept-0" #40 daemon prio=5 os_prio=0 tid=0x0000000020b50000 nid=0x682c runnable [0x0000000021f9e000]
   java.lang.Thread.State: RUNNABLE
	at java.net.DualStackPlainSocketImpl.accept0(Native Method)
	at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketImpl.java:131)
	at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
	at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:199)
	- locked <0x0000000777484ad8> (a java.net.SocksSocketImpl)
	at java.net.ServerSocket.implAccept(ServerSocket.java:545)
	at java.net.ServerSocket.accept(ServerSocket.java:513)
	at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
	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)

   Locked ownable synchronizers:
	- None

"YJP-TelemetryUpdater-2" #37 daemon prio=6 os_prio=0 tid=0x0000000020b4f800 nid=0x6508 in Object.wait() [0x000000002151e000]
   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.awt.EventQueue.invokeAndWait(EventQueue.java:1313)
	- locked <0x00000006ca6eaa30> (a java.awt.EventQueue$1AWTInvocationLock)
	at java.awt.EventQueue.invokeAndWait(EventQueue.java:1294)
	at com.yourkit.i.ah.if(a:222)
	at com.yourkit.i.h.if(a:222)
	at com.yourkit.i.h.if(a:275)
	at com.yourkit.i.h$a$1.run(a:3)
	at com.yourkit.api.ControllerImpl$31.perform(a:9)
	at com.yourkit.api.ControllerImpl.a(a:427)
	at com.yourkit.api.ControllerImpl.runBatch(a:365)
	at com.yourkit.i.h$a.run(a:48)

   Locked ownable synchronizers:
	- None

"LicenseChecker2" #36 prio=6 os_prio=0 tid=0x0000000020b4e800 nid=0x731c waiting on condition [0x000000002183f000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
	at java.lang.Thread.sleep(Native Method)
	at com.yourkit.util.c.a(a:60)
	at com.yourkit.Main1$a$1$1$1.run(a:6)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"LicenseChecker-/10.254.0.47" #35 prio=6 os_prio=0 tid=0x0000000020b4e000 nid=0x5944 runnable [0x000000002164f000]
   java.lang.Thread.State: RUNNABLE
	at java.net.TwoStacksPlainDatagramSocketImpl.receive0(Native Method)
	- locked <0x00000006c0368450> (a java.net.TwoStacksPlainDatagramSocketImpl)
	at java.net.TwoStacksPlainDatagramSocketImpl.receive(TwoStacksPlainDatagramSocketImpl.java:114)
	- locked <0x00000006c0368450> (a java.net.TwoStacksPlainDatagramSocketImpl)
	at java.net.DatagramSocket.receive(DatagramSocket.java:812)
	- locked <0x00000006c037d220> (a java.net.DatagramPacket)
	- locked <0x00000006c0368400> (a java.net.MulticastSocket)
	at com.yourkit.i.cz.a(a:23)
	at com.yourkit.i.cz$1.run(a:6)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"D3D Screen Updater" #34 daemon prio=7 os_prio=1 tid=0x0000000020b48000 nid=0x4cb0 in Object.wait() [0x000000002b77f000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at sun.java2d.d3d.D3DScreenUpdateManager.run(D3DScreenUpdateManager.java:423)
	- locked <0x00000006c036ffa0> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"GC Daemon" #32 daemon prio=2 os_prio=-2 tid=0x0000000020b4d000 nid=0x5cdc in Object.wait() [0x000000002990f000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000006c001c970> (a sun.misc.GC$LatencyLock)
	at sun.misc.GC$Daemon.run(GC.java:117)
	- locked <0x00000006c001c970> (a sun.misc.GC$LatencyLock)

   Locked ownable synchronizers:
	- None

"RMI Reaper" #31 prio=5 os_prio=0 tid=0x0000000020b4c800 nid=0xa188 in Object.wait() [0x000000002979f000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000006c0307700> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	- locked <0x00000006c0307700> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at sun.rmi.transport.ObjectTable$Reaper.run(ObjectTable.java:351)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"RMI TCP Accept-0" #30 daemon prio=5 os_prio=0 tid=0x0000000020b4b800 nid=0x76a4 runnable [0x000000002963f000]
   java.lang.Thread.State: RUNNABLE
	at java.net.DualStackPlainSocketImpl.accept0(Native Method)
	at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketImpl.java:131)
	at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
	at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:199)
	- locked <0x00000006c0140428> (a java.net.SocksSocketImpl)
	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)

   Locked ownable synchronizers:
	- None

"RMI TCP Accept-56908" #29 daemon prio=5 os_prio=0 tid=0x0000000020b4b000 nid=0x3480 runnable [0x00000000294ff000]
   java.lang.Thread.State: RUNNABLE
	at java.net.DualStackPlainSocketImpl.accept0(Native Method)
	at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketImpl.java:131)
	at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
	at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:199)
	- locked <0x00000006c001cda8> (a java.net.SocksSocketImpl)
	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)

   Locked ownable synchronizers:
	- None

"YJP-ThreadPool-1" #28 daemon prio=6 os_prio=0 tid=0x0000000020b4a000 nid=0x5414 waiting on condition [0x000000002813e000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c001d378> (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 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at com.yourkit.i.i.c.c$1$1.run(a:5)

   Locked ownable synchronizers:
	- None

"TimerQueue" #27 daemon prio=5 os_prio=0 tid=0x0000000020b49800 nid=0x2b90 waiting on condition [0x0000000027d8e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c0030580> (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.DelayQueue.take(DelayQueue.java:223)
	at javax.swing.TimerQueue.run(TimerQueue.java:171)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x00000006c00305f0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"AWT-EventQueue-1" #26 prio=6 os_prio=0 tid=0x0000000020b48800 nid=0x49c4 runnable [0x0000000025b5c000]
   java.lang.Thread.State: RUNNABLE
	at javax.swing.table.JTableHeader.getHeaderRect(JTableHeader.java:358)
	at com.yourkit.i.b.z.if(a:17)
	at com.yourkit.i.b.z.new(a:221)
	at com.yourkit.i.p.b$c.a(a:19)
	at com.yourkit.i.p.b$c.doLayout(a:16)
	at java.awt.Container.validateTree(Container.java:1693)
	at java.awt.Container.validate(Container.java:1628)
	- locked <0x00000006c0000830> (a java.awt.Component$AWTTreeLock)
	at com.yourkit.i.a3.doLayout(a:152)
	at java.awt.Container.validateTree(Container.java:1693)
	at java.awt.Container.validateTree(Container.java:1702)
	at java.awt.Container.validateTree(Container.java:1702)
	at java.awt.Container.validate(Container.java:1628)
	- locked <0x00000006c0000830> (a java.awt.Component$AWTTreeLock)
	at com.yourkit.i.a3.doLayout(a:152)
	at java.awt.Container.validateTree(Container.java:1693)
	at java.awt.Container.validateTree(Container.java:1702)
	at java.awt.Container.validateTree(Container.java:1702)
	at java.awt.Container.validate(Container.java:1628)
	- locked <0x00000006c0000830> (a java.awt.Component$AWTTreeLock)
	at javax.swing.plaf.basic.BasicTabbedPaneUI.ensureCurrentLayout(BasicTabbedPaneUI.java:1447)
	at javax.swing.plaf.basic.BasicTabbedPaneUI.getTabBounds(BasicTabbedPaneUI.java:1467)
	at com.yourkit.i.cs.a(a:295)
	at com.yourkit.i.cs.processMouseEvent(a:198)
	at java.awt.Component.processEvent(Component.java:6290)
	at java.awt.Container.processEvent(Container.java:2234)
	at com.yourkit.i.cs.processEvent(a:172)
	at java.awt.Component.dispatchEventImpl(Component.java:4881)
	at java.awt.Container.dispatchEventImpl(Container.java:2292)
	at java.awt.Component.dispatchEvent(Component.java:4703)
	at java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4898)
	at java.awt.LightweightDispatcher.retargetMouseEnterExit(Container.java:4686)
	at java.awt.LightweightDispatcher.trackMouseEnterExit(Container.java:4665)
	at java.awt.LightweightDispatcher.processMouseEvent(Container.java:4514)
	at java.awt.LightweightDispatcher.dispatchEvent(Container.java:4462)
	at java.awt.Container.dispatchEventImpl(Container.java:2278)
	at java.awt.Window.dispatchEventImpl(Window.java:2750)
	at java.awt.Component.dispatchEvent(Component.java:4703)
	at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:758)
	at java.awt.EventQueue.access$500(EventQueue.java:97)
	at java.awt.EventQueue$3.run(EventQueue.java:709)
	at java.awt.EventQueue$3.run(EventQueue.java:703)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$1.doIntersectionPrivilege(ProtectionDomain.java:75)
	at java.security.ProtectionDomain$1.doIntersectionPrivilege(ProtectionDomain.java:86)
	at java.awt.EventQueue$4.run(EventQueue.java:731)
	at java.awt.EventQueue$4.run(EventQueue.java:729)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$1.doIntersectionPrivilege(ProtectionDomain.java:75)
	at java.awt.EventQueue.dispatchEvent(EventQueue.java:728)
	at com.yourkit.Main1$b.dispatchEvent(a:34)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:201)
	at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
	at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)

   Locked ownable synchronizers:
	- None

"AWT-EventQueue-0" #20 prio=6 os_prio=0 tid=0x0000000020831000 nid=0x3fa4 waiting on condition [0x0000000024cae000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c00e6250> (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.awt.EventQueue.getNextEvent(EventQueue.java:554)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:170)
	at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
	at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)

   Locked ownable synchronizers:
	- None

"RMI Scheduler(0)" #19 daemon prio=5 os_prio=0 tid=0x000000002086c800 nid=0x47dc waiting on condition [0x000000002481f000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c01417e0> (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.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"YJP-ThreadPool-0" #18 daemon prio=5 os_prio=0 tid=0x0000000020854000 nid=0x4258 waiting on condition [0x000000002444e000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000006c001d378> (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 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at com.yourkit.i.i.c.c$1$1.run(a:5)

   Locked ownable synchronizers:
	- None

"DestroyJavaVM" #16 prio=5 os_prio=0 tid=0x000000000286f000 nid=0xa3c8 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"AWT-Windows" #13 daemon prio=6 os_prio=0 tid=0x000000001ea69800 nid=0x5fc4 runnable [0x000000002124e000]
   java.lang.Thread.State: RUNNABLE
	at sun.awt.windows.WToolkit.eventLoop(Native Method)
	at sun.awt.windows.WToolkit.run(WToolkit.java:306)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"AWT-Shutdown" #12 prio=5 os_prio=0 tid=0x000000001e940800 nid=0x6e4c in Object.wait() [0x000000001feee000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000006c002e9b0> (a java.lang.Object)
	at java.lang.Object.wait(Object.java:502)
	at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:295)
	- locked <0x00000006c002e9b0> (a java.lang.Object)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"Java2D Disposer" #11 daemon prio=10 os_prio=2 tid=0x000000001e93f000 nid=0x5920 in Object.wait() [0x000000002104e000]
   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 <0x00000006c002cac8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at sun.java2d.Disposer.run(Disposer.java:148)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- None

"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x000000001e78e800 nid=0x5ea4 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C1 CompilerThread3" #9 daemon prio=9 os_prio=2 tid=0x000000001e784800 nid=0x5ffc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread2" #8 daemon prio=9 os_prio=2 tid=0x000000001e784000 nid=0x54fc runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread1" #7 daemon prio=9 os_prio=2 tid=0x000000001e781000 nid=0x5b48 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"C2 CompilerThread0" #6 daemon prio=9 os_prio=2 tid=0x000000001e728000 nid=0x5294 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x000000001e727000 nid=0xa700 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x000000001e726000 nid=0x8220 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000000e83a000 nid=0x744c in Object.wait() [0x000000001fc5f000]
   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 <0x00000006c01672e0> (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)

   Locked ownable synchronizers:
	- None

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000000e839000 nid=0x5128 in Object.wait() [0x000000001fa2f000]
   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$ReferenceHandler.run(Reference.java:157)
	- locked <0x00000006c01674f8> (a java.lang.ref.Reference$Lock)

   Locked ownable synchronizers:
	- None

"VM Thread" os_prio=2 tid=0x000000001e6d3000 nid=0x9894 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00000000028ed800 nid=0x6488 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00000000028f0000 nid=0x62a0 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00000000028f1800 nid=0x4514 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00000000028f3800 nid=0x88c8 runnable 

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00000000028f6800 nid=0x3504 runnable 

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00000000028f7800 nid=0x49b8 runnable 

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00000000028fb000 nid=0x20e8 runnable 

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00000000028fc000 nid=0x4db0 runnable 

"VM Periodic Task Thread" os_prio=2 tid=0x000000001e791800 nid=0x205c waiting on condition 

JNI global references: 698

Anton Katilin
Posts: 6172
Joined: Wed Aug 11, 2004 8:37 am

Re: Thread#sleep eats CPU while sampling

Post by Anton Katilin »

Hi,

When on, stack telemetry does the same thread sampling, but with a much bigger period than that of CPU sampling (1 second and 20 ms, respectively):
https://www.yourkit.com/docs/java/help/threads.jsp

If there are so many threads that even a single sample results in a CPU hit, then either avoid using (i.e. don't turn on) the profiling modes which use the sampling - CPU sampling and stack telemetry - or increase their sampling periods to make the CPU hits less frequent.

Best regards,
Anton
Post Reply