Why is java ExecutorService newSingleThreadExecutor spawning two threads?

Question

I have a sample java code below which if run as a console application behaves as I expected ( spawning a single thread to execute the runnable).

The strange behavior (spawning two threads - sample below) I see is when I run this sample as a service application using Apache's prunsrv64.exe.

I am testing this on a Windows 7 machine - 64bit.

Sample Output:

   Thread -28 Current time: 09:50:11 AM
   Thread -52 Current time: 09:50:12 AM
   Thread -28 Current time: 09:50:21 AM
   Thread -52 Current time: 09:50:22 AM
   Thread -28 Current time: 09:50:31 AM
   Thread -52 Current time: 09:50:32 AM

Sample Code:

import java.util.Date;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class ExecutorTest{
    public void testIt(){
        ExecutorService ex = Executors.newSingleThreadExecutor();
        ex.execute(new Runnable(){
            public void run() {
                while(true){
                    System.out.printf("Thread -" + Thread.currentThread().getId() + " Current time: %tr%n", new Date());
                    try{
                        Thread.sleep(10000);    
                    }catch(InterruptedException ie){
                        ie.printStackTrace();
                    }                   
                }

            }
        });     
    }
}

Thanks.

Update: Just to clarify I am calling this code as follows:

    ExecutorTest tester = new ExecutorTest();
    tester.testIt();

The same code without changes is behaving differently when run as console application and a service application as I mentioned above.

Update 2: I added a second tester which uses a ScheduledExecutorService. The behavior is the same.

Update2 Output:

Using ScheduledExecutorService.
Thread Id outside Runnable -1
Thread -53 Current time: 10:58:15 AM
Thread -28 Current time: 10:58:24 AM
Thread -53 Current time: 10:58:25 AM
Thread -28 Current time: 10:58:34 AM
Thread -53 Current time: 10:58:35 AM
Thread -28 Current time: 10:58:44 AM
Thread -53 Current time: 10:58:45 AM
Thread -28 Current time: 10:58:54 AM
Thread -53 Current time: 10:58:55 AM
Thread -28 Current time: 10:59:04 AM
Thread -53 Current time: 10:59:05 AM

Update 2 Code:

public void testItWithScheduled(){
    System.out.println("Using ScheduledExecutorService.");
    ScheduledExecutorService ex = Executors.newSingleThreadScheduledExecutor();
    System.out.println("Thread Id outside Runnable -" + Thread.currentThread().getId());
    ex.scheduleWithFixedDelay(new Runnable(){
        public void run() {
            System.out.printf("Thread -" + Thread.currentThread().getId() + " Current time: %tr%n", new Date());
        }
    },0L, 10, TimeUnit.SECONDS);        
}


called through:

    ExecutorTest tester = new ExecutorTest();
    tester.testItWithScheduled();

Update 3: Modified logging to add identity hash

Using ScheduledExecutorService.
Thread Id outside Runnable 1 with reference: 1370756928
Thread -53 Current time: 11:10:38 AM with reference: 1370756928
Thread -28 Current time: 11:10:47 AM with reference: 1939972532
Thread -53 Current time: 11:10:48 AM with reference: 1370756928
Thread -28 Current time: 11:10:57 AM with reference: 1939972532
Thread -53 Current time: 11:10:58 AM with reference: 1370756928
Thread -28 Current time: 11:11:07 AM with reference: 1939972532
Thread -53 Current time: 11:11:08 AM with reference: 1370756928

I would assume that you have your main thread running the program and then you are creating the `Executors.newSingleThreadExecutor();` which is creating another thread. Resulting in two threads. — Josef E., Dec 04 '14 at 15:12
Do you get 2 different thread ids if you place a println of getId() right before the while loop? — brummfondel, Dec 04 '14 at 15:29
Since this seems related to how you run the code rather than newSingleThreadExecutor(), please tell us a bit more about how you are packaging and running this application when you run it as a "service" ? Are your prunsrv64.exe referring to the [Apache Commons Daemon](http://commons.apache.org/proper/commons-daemon/procrun.html) project ? It'd be of advantage if you include *all* information that lets someone reproduce it(Which also mean the full source code, including the main() method). — nos, Dec 04 '14 at 15:45

John Vint · Accepted Answer · 2014-12-04T16:34:20.957

4

The only reasonable conclusion is that you (or the framework) are creating two references of ExecutorTest and executing it twice.

Add the identityHashCode of the object to your logging.

System.out.printf("Thread -" + Thread.currentThread().getId() + " Current time: %tr with reference: %s%n ", new Date(), System.identityHashCode(ExecutorTest.this));

The same code without changes is behaving differently when run as console application and a service application as I mentioned above.

You control exactly how many are being created here.

Edit Based on your third update.

My assumption is correct, the System.identityHashCode of an object is analogous to its memory location. As you can see the two values are different but if the ExecutorService was creating two threads, those values would be the same.

That means you are creating multiple instances. Maybe not you directly, but the framework is creating multiple of the same service and running them.

So this moves from a question of 'why is the executor service creating 2 threads' to 'why is my framework creating two service instances'. That question I cannot answer.

To clarify more clearly, imagine executing your test like this

ExecutorTest tester1 = new ExecutorTest();
tester1.testIt();
ExecutorTest tester2 = new ExecutorTest();
tester2.testIt();

That is similar to what is occurring in your application.

edited Dec 04 '14 at 16:34

answered Dec 04 '14 at 15:39

John Vint

39,695
7
78
108

It seems that a second reference is created not in my code though: reference: 1939972532 – tint si Dec 04 '14 at 16:29
Well, from the perspective of the ExecutorService, it doesn't matter. All you need to know is that another instance is in fact being created. The two logging statements are occurring from two separate instance – John Vint Dec 04 '14 at 16:31
John, I get what you mean. The next question is, why is the second instance only affecting inside the run. As you see from my output, the testItWithScheduled() method is getting called only once. This should also indicate that I am not creating two instances in my code or calling this twice. – tint si Dec 04 '14 at 16:39
@tintsi I see where your question lies. If what you're seeing is true, there isn't much of a conclusion that can be made from that. I want to say something is missing from these tests. Because I find it hard to believe you have two separate instances of `ExecutorTest` and only one had the method invoked. – John Vint Dec 04 '14 at 17:01
2

John, Thanks for the analysis. After looking further up in the logs, I noticed that the testItWithScheduled() method does get called twice using a new reference. – tint si Dec 04 '14 at 17:06

score 1 · Answer 2 · answered Dec 04 '14 at 16:27

I actually tried this code in my pc like this ,


    import java.util.Date;
    import java.util.concurrent.ExecutorService;
    import java.util.concurrent.Executors;

    public class ExecutorTest{
        public void testIt(){
            ExecutorService ex = Executors.newSingleThreadExecutor();
            ex.execute(new Runnable(){
                public void run() {
                    while(true){
                        System.out.printf("Thread -" + Thread.currentThread().getId() + " Current time: %tr%n", new Date());
                        try{
                            Thread.sleep(1000);    
                        }catch(InterruptedException ie){
                            ie.printStackTrace();
                        }                   
                    }

                }
            });     
        }
        public static void main(String[] args) {
            ExecutorTest x = new ExecutorTest();
            x.testIt();
        }
    }

and I m getting only one thread,

Thread -10 Current time: 09:50:27 PM
Thread -10 Current time: 09:50:28 PM
Thread -10 Current time: 09:50:29 PM
Thread -10 Current time: 09:50:30 PM
Thread -10 Current time: 09:50:31 PM
Thread -10 Current time: 09:50:32 PM
Thread -10 Current time: 09:50:33 PM

so mostly there can be an error on the way you are instantiating the class

Why is java ExecutorService newSingleThreadExecutor spawning two threads?

2 Answers2

Linked