Why is an idle Java thread showing high CPU usage?

Question

I'm using Wildfly 11 with JDK 8 on Amazon Linux. I'm trying to figure out why a thread that is supposedly waiting is showing high CPU usage. I got the PID of my application server process like so

[jboss@prodmachine ~]$ ps -elf | grep java
0 S jboss     8844     1  0  80   0 - 28275 wait   15:30 ?        00:00:00 /bin/sh /usr/java/wildfly/bin/standalone.sh -c standalone.xml
0 S jboss     8896  8844 99  80   0 - 7337773 futex_ 15:30 ?      08:16:14 /usr/java/default/bin/java -D[Standalone] -server -Xms64m -Xmx25600m -XX:MetaspaceSize=96M -XX:MaxMetaspaceSize=1024m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman,com.newrelic -Djava.awt.headless=true -javaagent:/usr/java/wildfly/newrelic/newrelic.jar -Dorg.jboss.boot.log.file=/usr/java/wildfly/standalone/log/server.log -Dlogging.configuration=file:/usr/java/wildfly/standalone/configuration/logging.properties -jar /usr/java/wildfly/jboss-modules.jar -mp /usr/java/wildfly/modules org.jboss.as.standalone -Djboss.home.dir=/usr/java/wildfly -Djboss.server.base.dir=/usr/java/wildfly/standalone -c standalone.xml

and then I looked up the high Cpu uprocesses related to that

top -n 1 -H -p 8896

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                           
 9310 jboss     20   0 28.0g 4.4g  33m S 43.3 15.2   3:16.72 java                                                                               
 9207 jboss     20   0 28.0g 4.4g  33m S 13.8 15.2  42:00.05 java                                                                               
 9292 jboss     20   0 28.0g 4.4g  33m S 13.8 15.2   3:17.87 java

So the hex for "9310" is "0x245e" and when I did a thread dump with jstack that's what I looked for ...

[jboss@prodmachine ~]$ /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.181-8.b13.39.39.amzn1.x86_64/bin/jstack -l 8896 > /tmp/jstack.txt

revealed this

"default task-86" #272 prio=5 os_prio=0 tid=0x00000000090ee800 nid=0x245e waiting on condition [0x00007f3220cee000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x0000000181c9e050> (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:1074)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

but everything I've read indicates that threads int he "WAITING" state should take up no CPU resources. So why am I seeing this bizarre result? Did I screw something up along the way?

user_10275943 · Answer

Instead of using the command line to monitor your threads activities, use Java visual VM it's pretty much better and will extremely help you.

Does threads int the "WAITING" or "SLEEPING" state use CPU?

There is time taken to enter and exit the sleep/waiting state. This is cost is relatively small but non-trivial if called enough.

In the case of wait(), it can wake spuriously so if you using it in a loop as is idiomatic, this could burn quite a bit of CPU in theory. In practice, this happen rarely in my experience but often enough that if you forget to use a loop it can create hard to reproduce bugs.

Why is an idle Java thread showing high CPU usage?

1 Answers