Odd behavior with Runnable and ExecutorService

Question

I'm getting some really weird behavior with multithreading. I have two classes: DipoleTester and Dipole.

DipoleTester attempts to create several Dipole objects, and then run them asynchronously. The problem is that DipoleTester just runs all of its Dipole objects at once, rather than 2 at a time.

Here is DipoleTester:

public class DipoleTester {
    public static String DIR = "./save/";
    public static void main(String[] args) throws InterruptedException {
        Dipole trial;
        ExecutorService service = Executors.newFixedThreadPool(2);      

        for (int r = 10; r < 13; r += 1) {
            double radius = (double) r / 10000.0;
            for (int matType = 0; matType < 3; matType++) {
                String name = "Simple_mat"+matType + "_rad" + radius;
                trial = new DipoleSimple(DIR + "Simple/", name);
                trial.materialType = matType;
                trial.RADIUS = radius;
                service.submit(trial);

            }
        }
        service.shutdown();
        service.awaitTermination(100, TimeUnit.HOURS);
    }
}

And here are the (relevant bits) from Dipole

public abstract class Dipole implements Runnable{
    ...     
    public void run() {
        initiate();
    }
    public void initiate() {
        DateFormat dateFormat = new SimpleDateFormat("MM/dd/yyyy HH:mm:ss");
        Date date = new Date();
        System.out.println(dateFormat.format(date) + ": Starting: " + NAME);
        model = ModelUtil.create(NAME);
        model.modelNode().create("mod1");
        makeParams();
        makeVariables();
        try {
            Thread.sleep(5000);
        } catch (InterruptedException e) {
            // TODO Auto-generated catch block
            e.printStackTrace();
        }
    }
    ...
}

The problem now is that all the threads execute at once, even with the thread.sleep(5000)! I have no idea what's going on. Here is the console output:

05/08/2013 19:17:31: Starting: Simple_mat0_rad0.001
05/08/2013 19:17:31: Starting: Simple_mat1_rad0.001
05/08/2013 19:17:31: Starting: Simple_mat2_rad0.001
05/08/2013 19:17:31: Starting: Simple_mat0_rad0.0011
05/08/2013 19:17:31: Starting: Simple_mat1_rad0.0011
05/08/2013 19:17:31: Starting: Simple_mat2_rad0.0011
05/08/2013 19:17:31: Starting: Simple_mat0_rad0.0012
05/08/2013 19:17:31: Starting: Simple_mat1_rad0.0012
05/08/2013 19:17:31: Starting: Simple_mat2_rad0.0012

Answer 1

Your Runnable task is throwing an exception before it gets to the Thread.sleep() call. This allows the next task to begin execution. All the tasks fail in such quick succession that all appear to run concurrently.

Make the call to Thread.sleep() the first thing you do in your run() method and you will see that only two threads run at a time.

To detect such failures, you'll need to examine the Future instance that results from each call to submit(). There are other methods for submitting a list of tasks in bulk, and waiting for them to complete, that might be better suited to your application.