Analyzing the java thread dumps

Question

"Star Builder 129" daemon prio=10 tid=0x00007f41bd8f6000 nid=0x152b0 waiting on condition [0x00007f445cd1a000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00007f59c9e1c278> (a java.util.concurrent.FutureTask)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:422)
        at java.util.concurrent.FutureTask.get(FutureTask.java:199)

I have spent the last day trying to understand what this actually means. There is not enough information about this, or I could not find anything useful.

What does "waiting on condition" mean? Are we waiting on a monitor ? what does "0x00007f445cd1a000" indicate?

What does "parking to wait for" mean? And what is "0x00007f59c9e1c278"?

Source code:

        List<FutureTask<List<FileStatus>>> tasks = new LinkedList<FutureTask<List<FileStatus>>>();
    for(int idx = 0, len = Math.max(1,numberOfThreads()); idx < len; ++idx) {
        StatusWorker worker = new StatusWorker(this, qualifiedPath, userFilter, prefixQueue, prefixCounter, statusCounter);
        FutureTask<List<FileStatus>> task = new FutureTask<List<FileStatus>>(worker);
        threadPool.execute(task);
        tasks.add(task);
    }

    try {
        List<FileStatus> statuses = new LinkedList<FileStatus>();

        for(FutureTask<List<FileStatus>> task : tasks) {
            statuses.addAll(task.get(FILE_LISTING_TIMEOUT, TimeUnit.SECONDS));
            logger.debug("Result from task [{}]", task);
        }

Answer 1

This might point to a coding problem. The code waits for the completion of a FutureTask which is not yet executed.

Find below a snippet for demonstration

Future.java

import java.util.concurrent.Callable;
import java.util.concurrent.FutureTask;
import java.util.concurrent.TimeUnit;

public class Future {

    public static void main(String[] args) throws Exception {
        FutureTask<String> future = new FutureTask<>(
                new Callable<String>() {
                    @Override
                    public String call() throws InterruptedException {
                        return "foo";
                    }
                });
        String get = future.get(30, TimeUnit.SECONDS);
        System.out.println("get = " + get);
    }
}

run in session 1

javac Future.java
java Future

run in session 2

$ jps
...
12345 Future
jstack -l 12345 > jstack.12345.log

note: 12345 is the PID of the running java Future process

content of jstack.12345.log

    "main" #1 prio=5 os_prio=0 tid=0x000000000273b000 nid=0x2b24 waiting on condition [0x0000000002abf000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x0000000781973910> (a java.util.concurrent.FutureTask)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:426)
        at java.util.concurrent.FutureTask.get(FutureTask.java:204)
        at Future.main(Future.java:19)

edit Based on the posted code snippet the described situation can happen quite easily. Referring to the javadoc of Executor.execute

Executes the given command at some time in the future.

at some time in the future which means not immediately at the invocation of execute. So you might reach the line task.get(...) before the task is actually executed. Your thread pool also might not able to run numberOfThreads() threads at the same time.

A small example to demonstrate (run the same commands as described earlier). We create a thread pool which executes only one task at the time. We assign two tasks to that pool. Immediately after calling executor.execute(..) for both tasks we wait for the result of the second task. As the first task is a long running one, we step into the situation you discover.

Future.java

public class Future {

    public static void main(String[] args) throws Exception {
        FutureTask<String> future1 = new FutureTask<>(
                () -> {
                    System.out.println("future1");
                    TimeUnit.SECONDS.sleep(50);
                    return "finished future1";
                });

        FutureTask<String> future2 = new FutureTask<>(
                () -> {
                    System.out.println("future2");
                    return "finished future2";
        });

        ExecutorService executor = Executors.newFixedThreadPool(1);
        executor.execute(future1);
        executor.execute(future2);

        String get = future2.get(30, TimeUnit.SECONDS);
    }
}

content of jstack.12345.log

"pool-1-thread-1" #9 prio=5 os_prio=0 tid=0x00007ff50811c000 nid=0x5a5c waiting on condition [0x00007ff4e7365000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at java.lang.Thread.sleep(Thread.java:340)
    at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
    at concurrent.Future$1.call(Future.java:19)
    at concurrent.Future$1.call(Future.java:15)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    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)

"main" #1 prio=5 os_prio=0 tid=0x00007ff50800a000 nid=0x5a4d waiting on condition [0x00007ff50e314000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000ec03dda8> (a java.util.concurrent.FutureTask)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:426)
    at java.util.concurrent.FutureTask.get(FutureTask.java:204)
    at concurrent.Future.main(Future.java:36)

pool-1-thread-1 - is the dump for future1 which currently sleeps (to simulate the long running task)

main - is the dump for future2.get(30, TimeUnit.SECONDS), which waits for the result of future2, which actually is not yet started.