Java threading and outputstream printinng issue

Question

I am trying to create 5 different threads and try to print a static object in their run method every time incrementing the count of static variable by one

Here is the sample output of the program

pool-1-thread-1 Static Value before update 19
Thread going to sleep pool-1-thread-1
pool-1-thread-4 Static Value before update 19
Thread going to sleep pool-1-thread-4
pool-1-thread-3 Static Value before update 19
Thread going to sleep pool-1-thread-3
pool-1-thread-2 Static Value before update 19
Thread going to sleep pool-1-thread-2
pool-1-thread-5 Static Value before update 19
Thread going to sleep pool-1-thread-5
Thread coming out of sleep pool-1-thread-3  StaticTest.sInt 19
Thread coming out of sleep pool-1-thread-4  StaticTest.sInt 19
Thread coming out of sleep pool-1-thread-1  StaticTest.sInt 19
Thread coming out of sleep pool-1-thread-5  StaticTest.sInt 19
Thread coming out of sleep pool-1-thread-2  StaticTest.sInt 19

**pool-1-thread-5  OLD value 22 Static Value after update 23**
pool-1-thread-1  OLD value 21 Static Value after update 22
pool-1-thread-4  OLD value 20 Static Value after update 21
pool-1-thread-3  OLD value 19 Static Value after update 20
pool-1-thread-2  OLD value 23 Static Value after update 24

Now my question is since Thread 3 came out of the sleep first it must have been printed first, however its thread 5 which is printed first and that too with value 22 i.e the static variable was incremented by three times before thread 5 gets hold of it, but why i see a random order while i am printing the incremented values to me it should have been printed in the same order the one they came out of sleep i.e thread 3/4/1/5/2

please pour in thoughts ? What I am missing why the random behaviour once the thread are back to running state after sleep

package com.test.concurrency;

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

public class StaticTest {

    public static Integer sInt = new Integer(19);

    public static void main(String[] args) {

        ExecutorService es = Executors.newCachedThreadPool();
        for (int i = 0; i < 5; i++) {
            es.execute(new StaticTask());
        }

    }

}

class StaticTask implements Runnable {

    public void run() {

        String name = Thread.currentThread().getName();
        System.out.println(name + " Static Value before update "
                + StaticTest.sInt);
        try {
            System.out.println("Thread going to sleep " + name);
            Thread.sleep(10);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        System.out.println("Thread coming out of sleep " + name + "  StaticTest.sInt " + StaticTest.sInt);

        int local = StaticTest.sInt;
        StaticTest.sInt = new Integer(local + 1);

        System.out.println(name + "  OLD value " + local +" Static Value after update "
                + StaticTest.sInt);

    }
}

Answer 1

You have no control or deterministic way of knowing which one will execute first, simply because you started the thread first doesn't mean that it will run first...

You are executing 5 threads in a loop, but no guarantee that the first will run first, 2nd run 2nd, and so on...

If you do want your threads to run in a specific order, you would have to do some join or wait/notify logic.

Answer 2

Chapters 17.4.3-5 in Java Language Specification 7 deal with what kinds of actions are subject to the happen-before rule and, in general, what can be expected of a multithreaded application's execution order.

Once you read those chapters, you will realize that there is fairly few guarantees to the execution sequence. What we may consider natural and take for granted is often invalid in case of multithreaded applications.

Moreover, there is the memory model - you access the variable sInt without synchronization. That way, you have no guarantee that the different threads will ever notice that the object reference has been changed. You have to use a common lock between the objects/threads that modify the variable to make sure it's change is even visible.

You can do it with synchronized block and a static object lock:

// in class:
static Object lock = new Object();


// in run():
synchronized(lock) {
    int local =StaticTest.sInt;
    StaticTest.sInt = new Integer(local + 1);
    System.out.println(name + "  OLD value " + local +" Static Value after update "
        + StaticTest.sInt);
}

That way the prints in synchronized will be ordered properly.

Answer 3

You should read up on concurrency in Java. You should never expect threads to run in any specific order -- especially without synchronizing code around a shared resource. Might want to start here.

Answer 4

The thread which is scheduled is depend on operating system,these threads have time slice

Answer 5

From the output, its clear that thread-3 is the one which woke up first (Yes, you are right) and then incremented the static int

pool-1-thread-5  OLD value 22 Static Value after update 23
pool-1-thread-1  OLD value 21 Static Value after update 22
pool-1-thread-4  OLD value 20 Static Value after update 21
pool-1-thread-3  OLD value 19 Static Value after update 20  --> static counter incr. from 19 to 20
pool-1-thread-2  OLD value 23 Static Value after update 24

In the above print statements, it is clear from the values they are printing that, the thread which woke up first, is doing increment and printing the value.

What is unpredictable is the print sequence.

If you think at low level, System.out.print statements are Asynchronous, thus the output

Answer 6

Now my question is since Thread 3 came out of the sleep first it must have been printed first, however its thread 5 which is printed first and that too with value 22

As there are 5 threads running concurrently, so the order in which the given set of statements are executed is not predictable. Even if the threads were come out in the order 3/4/1/5/2, it is not guaranteed that the same order will be preserved while executing the rest of the statements. That is why it is called Asynchronous execution.

It might have happened that threads 3, 4, 1 executed the statements

int local =StaticTest.sInt;
StaticTest.sInt = new Integer(local + 1);

one after another (in any order) and then thread 5 got the opportunity to execute the statements at one go:

int local =StaticTest.sInt;
StaticTest.sInt = new Integer(local + 1);
System.out.println(name + "  OLD value " + local +" Static Value after update "
                + StaticTest.sInt);

and you have got this printed on the console:

pool-1-thread-5  OLD value 22 Static Value after update 23

as the value of static variable StaticTest.sInt might have been already updated to 22 by threads 3, 4, 1.

And you should always use synchronized access to shared variables, so that changes made by one thread is visible to others and also with synchronized access, operations on shared variables are atomic:

public static synchronized Integer incrementSInt() {
    return StaticTest.sInt++;
}