Can ThreadPoolExecutor hang ?

The answer is well, it can and does. Below is a simple piece of code to produce one such hang

package com.misc.exercises;

import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;

class STPEHangTestThread implements Runnable
{

  private static int count = 0;

  public static void main(String args[])
  {              
        ScheduledExecutorService scheduledExecutor;
        scheduledExecutor = Executors.newScheduledThreadPool(1, new ThreadFactory()
        {
            public Thread newThread(Runnable r)
            {
                Thread t = new Thread(r);
                t.setName("MySchedulerThread");
                t.setDaemon(Boolean.TRUE);
                return t;
            }
        });
        scheduledExecutor.scheduleWithFixedDelay(new STPEHangTestThread(), 1, 5, TimeUnit.SECONDS);   

    while(true)
    {

    }
}     
  public void run()
  {

        if(count > 2 & count % 3 == 0)
            throw new RuntimeException("Exception throw !!!");
        System.out.println("Running");
        count++;   
  }
}

If you run this program the output would look like this,

Running
Running
Running

Why doesn’t is print “Running” although the program should keep executing forever? The answer lies in looking at the output of the jstack execution against the process like below,

C:\>jps
5572
1216 Jps
4036 STPEHangTestThread
756

Now run jstack against the process 4036

C:\>jstack -l 4036
2014-08-09 16:03:01
Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.21-b01 mixed mode):

"MySchedulerThread" daemon prio=6 tid=0x000000000b9c9000 nid=0x1ab4 waiting on condition [0x000000000d55e000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fb0590> (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:1079)
        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:722)

   Locked ownable synchronizers:
        - None

The thread dump of the “MySchedulerThread” looks interesting doesn’t it? This indicates a hung ThreadPoolExecutor. This is essentially because, the thread that was running on the scheduler thread threw an exception and terminated never to run again. Although the scheduler thread survived the exception, its pretty much useless at this point. In essence, restart of this application is the only alternative you have to solve this problem.

So how do you fix this? The below code is a modified version of the program posted above but with a try-catch block in the run method that catches the exception and lets the execution continue.

package com.misc.exercises;

import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ThreadFactory;
import java.util.concurrent.TimeUnit;

class STPECleanRunTestWorker implements Runnable
{

  private static int count = 0;

  public static void main(String args[])
  {              
        ScheduledExecutorService scheduledExecutor;
        scheduledExecutor = Executors.newScheduledThreadPool(1, new ThreadFactory()
        {
            public Thread newThread(Runnable r)
            {
                Thread t = new Thread(r);
                t.setName("MySchedulerThread");
                t.setDaemon(Boolean.TRUE);
                return t;
            }
        });
        scheduledExecutor.scheduleWithFixedDelay(new STPECleanRunTestWorker(), 1, 5, TimeUnit.SECONDS);   

    while(true)
    {

    }
}  

  STPECleanRunTestWorker()
  {

  }

  public void run() {
    try
    {
        if(count > 2 && count % 3 == 0)
            throw new RuntimeException("Exception throw !!!");
        System.out.println("Running");
        count++;
    }
    catch (Exception e)
    {
        System.out.println("Caught !!!");    
        e.printStackTrace();
        count++;
    }
  }
}

A similar exercise like above with jps and jstack would yield the result shown below,

C:\>jstack -l 6412
2014-08-09 16:10:48
Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.21-b01 mixed mode):

"MySchedulerThread" daemon prio=6 tid=0x000000000b5c7000 nid=0x1b98 waiting on condition [0x000000000d34e000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fb0868> (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:722)

   Locked ownable synchronizers:
        - None

Notice the difference in the states of the “MySchedulerThread”. In the first case its WAITING, but in this case it’s TIMED_WAITING.

One can argue both ways that, there should be a way to report that an exception has occurred when a thread pool executor’s thread got one. But the other side of the argument that the execution that failed is of the task that was submitted and should be handled by the submitter better. I do not know the design decisions that were behind this behavior, but its always better to catch any exceptions that may encounter or possibly just put a try catch block there to not jeopardize your executor.

A more simpler manifestation of the same problem can be done with the below code. Where a executor with 5 threads is started and never shut down.

package com.misc.exercises;

import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.BlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;

class TPEHangTest implements Runnable
{  
  String workerName;

  public static void main(String args[])
  {    
      BlockingQueue<Runnable> queue = new ArrayBlockingQueue<Runnable>(5);
      ThreadPoolExecutor executor = new ThreadPoolExecutor(5, 5, 5000, TimeUnit.SECONDS, queue);
      for (int j = 0; j < 5 ; j++)
      {
        executor.execute(new TPEHangTest("Worker - "+j));
      }      
      //executor.shutdown();
  }

  TPEHangTest(String name)
  {
    workerName = name;
  }

  public void run() {
    try
    {
        System.out.println(workerName + " ran");
    }
    catch (Exception e)
    {
        System.out.println("Worker run , Exception !!!");
        e.printStackTrace();
    }
  }
}

The program output would look like this,

Worker - 0 ran
Worker - 1 ran
Worker - 2 ran
Worker - 3 ran
Worker - 4 ran

The jstack output for this program would like this,

C:\>jps
6932 TPEHangTest
5572
3764 Jps
756

C:\>jstack -l 6932
2014-08-09 16:19:54
Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.21-b01 mixed mode):

"DestroyJavaVM" prio=6 tid=0x00000000021ac000 nid=0x530 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None

"pool-1-thread-5" prio=6 tid=0x000000000ba10000 nid=0x160c waiting on condition [0x000000000db4f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fadea0> (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 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:722)

   Locked ownable synchronizers:
        - None

"pool-1-thread-4" prio=6 tid=0x000000000ba0f800 nid=0x16fc waiting on condition [0x000000000d9af000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fadea0> (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 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:722)

   Locked ownable synchronizers:
        - None

"pool-1-thread-3" prio=6 tid=0x000000000ba0a800 nid=0x1804 waiting on condition [0x000000000d6df000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fadea0> (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 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:722)

   Locked ownable synchronizers:
        - None

"pool-1-thread-2" prio=6 tid=0x000000000ba06000 nid=0x434 waiting on condition [0x000000000d5df000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fadea0> (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 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:722)

   Locked ownable synchronizers:
        - None

"pool-1-thread-1" prio=6 tid=0x000000000ba04800 nid=0x1a20 waiting on condition [0x000000000cf5f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d5fadea0> (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 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:722)

   Locked ownable synchronizers:
        - None

In the above code, if the executor.shutdown() is not commented out, this program would gracefully terminate.

The lesson thus is that if you have an executor that is giving you non-daemon worker threads make sure you shut the executor down or else it could just be there WAITING.

On a recent project I worked, I needed to use the things extensively and in the process came across these things. I hope this helps you, if you already knew this then kudos !!!

Happy Coding !!!

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s